How to Install MariaDB Galera Cluster 5.5 on Debian 6 “Squeeze”

2 Comments

为什么是MariaDB，为什么是Galera，为什么是Debian，这些闲话都不说了，直入正题。

本文参考资料：AskMonty KB。

  1. 在两台机器上分别安装MariaDB Galera Cluster，可以使用两个虚拟机，互相之间IP可以ping通即可。
    由于apt-get是如此好用，因此请保证你的Debian可以联网，然后执行：
# apt-key adv --recv-keys --keyserver keyserver.ubuntu.com 0xcbcb082a1bb943db
# cd /etc/apt/sources.list.d/
--创建MariaDB.list文件
# vi MariaDB.list
--添加如下内容
# MariaDB 5.5 repository list - created 2013-04-25 09:13 UTC
# http://mariadb.org/mariadb/repositories/
deb http://mirrors.fe.up.pt/pub/mariadb/repo/5.5/debian squeeze main
deb-src http://mirrors.fe.up.pt/pub/mariadb/repo/5.5/debian squeeze main
--更新apt资源
# apt-get update
# apt-cache search mariadb
libmariadbclient-dev - MariaDB database development files
libmariadbclient18 - MariaDB database client library
libmariadbd-dev - MariaDB embedded database development files
libmysqlclient18 - Virtual package to satisfy external depends
mariadb-client - MariaDB database client (metapackage depending on the latest version)
mariadb-client-5.5 - MariaDB database client binaries
mariadb-client-core-5.5 - MariaDB database core client binaries
mariadb-common - MariaDB database common files (e.g. /etc/mysql/conf.d/mariadb.cnf)
mariadb-galera-server - MariaDB database server with Galera cluster
mariadb-galera-server-5.5 - MariaDB database server with Galera cluster binaries
mariadb-server - MariaDB database server (metapackage depending on the latest version)
mariadb-server-5.5 - MariaDB database server binaries
mariadb-server-core-5.5 - MariaDB database core server files
mariadb-test - MariaDB database regression test suite (metapackage depending on the latest version)
mariadb-test-5.5 - MariaDB database regression test suite
mysql-common - MariaDB database common files (e.g. /etc/mysql/my.cnf)
--只需要安装mariadb-galera-server即可，注意，会自动卸载Debian中预装的MySQL 5.1
# apt-get install mariadb-galera-server
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following extra packages will be installed:
  galera libaio1 libmariadbclient18 libmysqlclient18 mariadb-client-5.5 mariadb-client-core-5.5 mariadb-common mariadb-galera-server-5.5
Suggested packages:
  tinyca mariadb-test
The following packages will be REMOVED:
  mysql-client-5.1 mysql-server mysql-server-5.1 mysql-server-core-5.1
The following NEW packages will be installed:
  galera libaio1 libmariadbclient18 libmysqlclient18 mariadb-client-5.5 mariadb-client-core-5.5 mariadb-common mariadb-galera-server mariadb-galera-server-5.5
0 upgraded, 9 newly installed, 4 to remove and 46 not upgraded.
Need to get 32.3 MB of archives.
After this operation, 55.2 MB of additional disk space will be used.
Do you want to continue [Y/n]?
  1. 修改my.cnf文件，修改或者添加如下行，在两个节点中都修改。
# vi /etc/mysql/my.cnf
wsrep_cluster_name = my_test_cluster
wsrep_node_name = debian
wsrep_provider = /usr/lib/galera/libgalera_smm.so
wsrep_sst_method = mysqldump
binlog_format=ROW
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
innodb_locks_unsafe_for_binlog=1
--注意，默认配置MariiaDB只监听localhost，因此需要修改bind-address参数
第一个节点：bind-address		= 192.168.1.108
第二个节点：bind-address		= 192.168.1.109
  1. 启动第一个节点
--如果之前数据库已经启动，可以先关闭
# /etc/init.d/mysql stop
--启动MariaDB Galera Cluster
# /usr/bin/mysqld_safe --wsrep_cluster_address=gcomm:// > /dev/null 2>&1 &
  1. 启动第二个节点
--其中192.168.1.108是第一个节点MariaDB的监听IP
# /usr/bin/mysqld_safe --wsrep_cluster_address=gcomm://192.168.1.108 > /dev/null 2>&1 &
  1. 检查整个Cluster状态
--随便登入任何一台机器的MariaDB# mysql MariaDB [(none)]> show status like 'wsrep%';
+----------------------------+---------------------------------------+
| Variable_name              | Value                                 |
+----------------------------+---------------------------------------+
| wsrep_local_state_uuid     | 5947fd92-adb9-11e2-0800-8d35ba835f31  |
| wsrep_protocol_version     | 4                                     |
| wsrep_last_committed       | 9                                     |
| wsrep_replicated           | 0                                     |
| wsrep_replicated_bytes     | 0                                     |
| wsrep_received             | 2                                     |
| wsrep_received_bytes       | 198                                   |
| wsrep_local_commits        | 0                                     |
| wsrep_local_cert_failures  | 0                                     |
| wsrep_local_bf_aborts      | 0                                     |
| wsrep_local_replays        | 0                                     |
| wsrep_local_send_queue     | 0                                     |
| wsrep_local_send_queue_avg | 0.000000                              |
| wsrep_local_recv_queue     | 0                                     |
| wsrep_local_recv_queue_avg | 0.000000                              |
| wsrep_flow_control_paused  | 0.000000                              |
| wsrep_flow_control_sent    | 0                                     |
| wsrep_flow_control_recv    | 0                                     |
| wsrep_cert_deps_distance   | 0.000000                              |
| wsrep_apply_oooe           | 0.000000                              |
| wsrep_apply_oool           | 0.000000                              |
| wsrep_apply_window         | 0.000000                              |
| wsrep_commit_oooe          | 0.000000                              |
| wsrep_commit_oool          | 0.000000                              |
| wsrep_commit_window        | 0.000000                              |
| wsrep_local_state          | 4                                     |
| wsrep_local_state_comment  | Synced                                |
| wsrep_cert_index_size      | 0                                     |
| wsrep_causal_reads         | 0                                     |
| wsrep_incoming_addresses   | 192.168.1.108:3306,192.168.1.109:3306 |
| wsrep_cluster_conf_id      | 6                                     |
| wsrep_cluster_size         | 2                                     |
| wsrep_cluster_state_uuid   | 5947fd92-adb9-11e2-0800-8d35ba835f31  |
| wsrep_cluster_status       | Primary                               |
| wsrep_connected            | ON                                    |
| wsrep_local_index          | 0                                     |
| wsrep_provider_name        | Galera                                |
| wsrep_provider_vendor      | Codership Oy                          |
| wsrep_provider_version     | 23.2.4(r147)                          |
| wsrep_ready                | ON                                    |
+----------------------------+---------------------------------------+
40 rows in set (0.00 sec)
  1. 测试双活读写
--任选一个节点创建数据库，创建表，插入数据
MariaDB [(none)]> CREATE DATABASE IF NOT EXISTS my_db default charset utf8 COLLATE utf8_general_ci;
Query OK, 1 row affected (0.01 sec)

MariaDB [(none)]> connect my_db
Connection id:    8
Current database: my_db

MariaDB [my_db]> create table my_table (name varchar(20) not null default '') default charset utf8;
Query OK, 0 rows affected (0.00 sec)

MariaDB [my_db]> insert into my_table values('enmotech');
Query OK, 1 row affected (0.00 sec)

--在另一个节点查询并更新
MariaDB [my_db]> select * from my_table;
+----------+
| name     |
+----------+
| enmotech |
+----------+
1 row in set (0.00 sec)

MariaDB [my_db]> update my_table set name='enmotech_mysql' where name='enmotech';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

--在之前的节点查询
MariaDB [my_db]> select * from my_table;
+----------------+
| name           |
+----------------+
| enmotech_mysql |
+----------------+
1 row in set (0.00 sec)

本文仅仅是最简单的安装及功能测试，不论健壮性、高效性、容错性如何，至少这种双活数据库的配置比起Oracle的任何一种解决方案都简单。

About GETS, MISSES, SPIN_GETS, SLEEPS in V$LATCH

2 Comments

今天重新阅读Latch的文档，按照我自己的理解，对于vlatch视图中的以下几个字段再作一些解释。
以下参数都是对于Willing-to-wait模式的latch而言的，no-wait模式的latch获得情况统计值则在IMMEDIATE_GETS和IMMEDIATE_MISSES字段中。所有vlatch视图中统计值都是在获得了latch之后才更新的。

GETS：当尝试获取一个latch并最终获得的时候，该值加1，在一次请求中无论是经过多少次自旋多少次Sleep，该值只会加1.

MISSES：如果没能不经过自旋（spin）就获得latch，该值加1，在一次请求中无论是经过多少次自旋多少次Sleep，该值只会加1.

SPIN_GETS：如果经过自旋才获得latch，该值加1，在一次请求中无论是经过多少次自旋，该值只会加1；如果经过了下述的SLEEPS方式才获得的latch，那么该值不变。

SLEEPS：这是MISS之后进程除了自旋之外，可能采取的另外一种方式-睡眠，将等待信号量唤醒或者Timeout唤醒。可能是由于多次自旋以后，仍然无法获得latch，进程就停止占用CPU，进入Sleep状态；也可能是首次尝试获取latch失败以后就直接进入睡眠期（比如单个CPU的机器中）。Sleep以后获得latch，该值加1，如果一次Sleep以后被唤醒，但是却仍然无法获得latch，那么会再次自旋，还无法获得，再次Sleep（睡眠时间会逐渐变长），多次Sleep会累加该值。

SQL> select count(*) from v$latch where MISSES=0;

  COUNT(*)
----------
       484

如上所示，这些latch都是一次请求就直接成功了，连一次Miss都没有。只要MISSES=0，那么SPIN_GETS和SLEEPS也一定等于0。

SQL> select NAME,GETS,MISSES,SPIN_GETS,SLEEPS from v$latch where MISSES>0 and SLEEPS=0;

NAME                                           GETS     MISSES  SPIN_GETS     SLEEPS
---------------------------------------- ---------- ---------- ---------- ----------
process allocation                            31557          8          8          0
session switching                             32313          3          3          0
process group creation                        24916          1          1          0
object stats modification                    171932         93         93          0
parameter table management                    38297         28         28          0
enqueue freelist latch                          407         28         28          0
FOB s.o list latch                            68402         13         13          0
FIB s.o chain latch                             416          1          1          0
resmgr:free threads list                      29002         55         55          0
resmgr group change latch                   1691466         79         79          0
channel handle pool latch                     28121          4          4          0
message pool operations parent latch          97758        128        128          0
ksv class latch                               25738         66         66          0
OS process allocation                       2402435          7          7          0
ksz_so allocation latch                       24916          8          8          0
mostly latch-free SCN                        931660        715        715          0
lgwr LWN SCN                                 930897         73         73          0
Consistent RBA                               807421         43         43          0
multiblock read objects                      256976         10         10          0
cache table scan latch                        95413          5          5          0
managed standby latch                         32933         15         15          0
list of block allocation                      64850         24         24          0
transaction allocation                       199415         55         55          0
KTF sga latch                                  7195          2          2          0
resmgr:resource group CPU method               8868         21         21          0
parameter list                                59369          8          8          0
job_queue_processes free list latch             699          1          1          0
process queue reference                        5500          1          1          0
parallel query alloc buffer                  163672          1          1          0
hash table modification latch                 52632          6          6          0
temporary table state object allocation        2939         14         14          0
SQL memory manager latch                      41293          1          1          0
SQL memory manager workarea list latch     28598806         49         49          0
session state list latch                      34530          1          1          0

34 rows selected.

如上所示，这些latch都有请求没有立刻成功的情况，因此都需要Spin片刻然后再次尝试获取，但是却都在Spin一次或者几次以后（在第一次Sleep之前最多自旋2000次，受隐含参数_spin_count控制）就成功获得了latch，注意所有行的MISSES=SPIN_GETS，也就是说如果某个latch在被尝试获取的时候从来都没有让进程Sleep过，那么只要出现1次Miss，就必须有至少1次Spin，而直到成功获得latch之前，无论有多少次Spin，SPIN_GETS值都始终只是加了1。

SQL> select NAME,GETS,MISSES,SPIN_GETS,SLEEPS from v$latch where MISSES>0 and MISSES<>SPIN_GETS;

NAME                                           GETS     MISSES  SPIN_GETS     SLEEPS
---------------------------------------- ---------- ---------- ---------- ----------
post/wait queue                             2176086       6243       6215         28
call allocation                              140862         79         50         29
session allocation                          1366266        208        194         14
session idle bit                           21495388       2581       2552         29
ksuosstats global area                       124206         13          0         13
messages                                   16534632       7141       7076         66
enqueue hash chains                        14685159       6740       6613        127
channel operations parent latch             6197125        261        233         28
active service list                         1343611         36         17         19
OS process: request allocation                24916         16          7          9
cache buffers lru chain                     3932233       3750       3587        166
active checkpoint queue latch               1657410        315        283         32
checkpoint queue latch                     36991888        796        759         37
cache buffers chains                      385956869      13902      13573        335
cache buffer handles                         115915          1          0          1
simulator lru latch                         1730616         70         61          9
simulator hash latch                       11343463         16         11          5
object queue header operation              24499957       7389       7149        241
object queue header heap                    6170931        465        459          6
archive process latch                         99017         77         12         65
redo writing                                4799991       1133       1131          2
redo allocation                             2703585       1256       1022        234
DML lock allocation                         2340322        302        291         11
dummy allocation                              25610         44         26         18
undo global data                            5721900       1143       1126         17
sort extent pool                              55723         88         87          1
space background task latch                 1653230      12640      12624         17
sequence cache                                37261          6          0          7
row cache objects                          57918735     298666     298342        334
shared pool                                14914798      80691      71271      12265
resmgr:actses change state                    12453          1          0          1
resmgr:schema config                        1792347       2144       2124         20
shared pool simulator                        645495         44         43          1
hash table column usage latch                 73186        300        299          1
qmn task queue latch                         179150          8          0          8

35 rows selected.

如上所示，只要曾经MISS过，但MISSES<>SPIN_GETS，那么必然意味着会有SLEEPS出现。SLEEPS之后，就不再累加本次的SPIN_GETS，因此所有的SPIN_GETS值才会都小于MISSES。
注意到其中有多个latch，完全没有经过Spin，而是每次都直接Sleep了，我的理解是对于某些latch，Oracle就直接选择了Sleep方式而不会尝试自旋（即使是在多CPU机器中）。以下这些latch都是这种模式，不会进行Spin，而是直接进入Sleep状态，等待唤醒然后再尝试获取latch。

SQL> select NAME,GETS,MISSES,SPIN_GETS,SLEEPS from v$latch where SPIN_GETS=0 and SLEEPS>0;

NAME                                           GETS     MISSES  SPIN_GETS     SLEEPS
---------------------------------------- ---------- ---------- ---------- ----------
ksuosstats global area                       124216         13          0         13
cache buffer handles                         115915          1          0          1
sequence cache                                37261          6          0          7
resmgr:actses change state                    12454          1          0          1
qmn task queue latch                         179166          8          0          8

希望以上描述可以更清晰地了解Latch是如何获得的，总结一下，在v$latch中，
1. MISSES=0: 表示请求以后就立刻获得了latch。
2. MISSES>0 and SLEEPS=0：表示请求以后没有获得latch，但是通过自旋获得了latch。
3. MISSES>0 and SLEEPS>0：表示请求以后没有获得latch，并且通过2000次自旋也没有获得latch，从而进入了Sleep；或者根本没有自旋就直接进入了Sleep。

DBA, If don’t know what you are doing, please don’t do

14 Comments

今天收到一个发过来请求帮助的case，Oracle数据库无法启动，请求帮助恢复。仔细阅读了发过来的告警日志，这是一个典型的“事情越弄越糟”的案例。

以下就来根据告警日志，一条一条地回顾这位DBA是如何将数据库弄到完全启动不了的。

故障最开始是从1月11日的凌晨3:30开始出现，数据库在归档的时候，意外发现某个控制文件的头块全部被清零了，这可能是存储本身的问题，并非人为。

Fri Jan 11 03:30:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Master background archival failure: 227
Fri Jan 11 03:31:24 2013
Hex dump of (file 0, block 1) in trace file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc
Corrupt block relative dba: 0x00000001 (file 0, block 1)
Completely zero block found during control file header read
Fri Jan 11 03:31:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Fri Jan 11 03:31:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Fri Jan 11 03:30:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Fri Jan 11 03:30:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Fri Jan 11 03:30:24 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_arc1_3031.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'

接下来，数据库痛苦地挣扎了半小时，期间不停地报相同的ORA-00227错误。一直到凌晨4:01，终于CKPT进程也发现无法更新控制文件头部，于是强势地将数据库直接关闭了。

Fri Jan 11 04:01:25 2013
Hex dump of (file 0, block 1) in trace file /oracle/admin/dpdata/bdump/dpdata_ckpt_3007.trc
Corrupt block relative dba: 0x00000001 (file 0, block 1)
Completely zero block found during control file header read
Fri Jan 11 04:01:25 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_ckpt_3007.trc:
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
Fri Jan 11 04:01:25 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_ckpt_3007.trc:
ORA-00227: corrupt block detected in control file: (block 1, # blocks 1)
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
CKPT: terminating instance due to error 227
Fri Jan 11 04:01:25 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_pmon_2997.trc:
ORA-00227: corrupt block detected in control file: (block , # blocks )
Fri Jan 11 04:01:26 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_psp0_2999.trc:
ORA-00227: corrupt block detected in control file: (block , # blocks )
Instance terminated by CKPT, pid = 3007

接下来的5个小时，数据库静静地躺在机房里，没有人知道这个数据库已经挂掉了，一直到上午DBA来上班。他发现数据库无法访问，于是尝试重新启动数据库。

Fri Jan 11 09:15:51 2013
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Autotune of undo retention is turned on.

自然数据库无法正常启动，连mount状态都无法进入，因为某个控制文件头部已经损坏了。告警日志的信息明确地说明了无法读取control03.ctl文件的头块，因此在尝试mount数据库的时候报了ORA-00205错误。

Fri Jan 11 09:15:56 2013
ALTER DATABASE   MOUNT
Fri Jan 11 09:15:56 2013
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
ORA-27047: unable to read the header block of file
Additional information: 2
Fri Jan 11 09:15:59 2013
ORA-205 signalled during: ALTER DATABASE   MOUNT...
Fri Jan 11 09:19:31 2013
Starting ORACLE instance (normal)
Fri Jan 11 09:19:43 2013
alter database mount
Fri Jan 11 09:19:43 2013
ORA-00202: control file: '/oracle/oradata/dpdata/control03.ctl'
ORA-27047: unable to read the header block of file
Additional information: 2
Fri Jan 11 09:19:43 2013
ORA-205 signalled during: alter database mount

接下来，这位DBA开始反复地关闭实例，又启动实例。这样的操作一直持续了1个小时，一直到上午的10:28，可以想象这是多么纠结的一个小时。忠告: 除非十分特殊的恢复案例，否则反复起停数据库实例是于事无补的。

Shutting down instance: further logons disabled
Fri Jan 11 09:23:47 2013
Stopping background process CJQ0
……
Fri Jan 11 09:38:02 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 09:43:00 2013
Shutting down instance: further logons disabled
……
Fri Jan 11 09:43:58 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 09:55:34 2013
ALTER DATABASE CLOSE NORMAL
……
Fri Jan 11 09:56:55 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 10:28:10 2013
ALTER DATABASE CLOSE NORMAL

接下来10:29的再次重新启动数据库实例之前，DBA终于意识到可能是控制文件出现了问题，因此修改了初始化参数，将报错的control03.ctl文件从初始化参数control_files中去掉了。这次数据库得以正常启动。

Fri Jan 11 10:29:20 2013
Starting ORACLE instance (normal)
……
control_files            = /data1/oradata/dpdata/control01.ctl, /data1/oradata/dpdata/control02.ctl
……
Fri Jan 11 10:29:37 2013
Completed: ALTER DATABASE OPEN

而DBA也迅速地作了一次备份控制文件的操作，但是正是这个操作引导到了后面噩梦一般的结果。

Fri Jan 11 10:36:14 2013
alter database backup controlfile to trace
Fri Jan 11 10:36:14 2013
Completed: alter database backup controlfile to trace

数据库又平稳地运行了一个上午，这种宁静到下午14:16的时候被打破，数据库开始报ORA-600错误，并且在CKPT进程作检查点的时候，报数据文件10和31的文件头部无法被正确读取。如果不是更深层次的原因，那么这可能仍然是跟凌晨时候控制文件意外损坏时候的故障一样，也许是存储子系统本身的问题。

Fri Jan 11 14:16:07 2013
Errors in file /oracle/admin/dpdata/udump/dpdata_ora_22240.trc:
ORA-00600: internal error code, arguments: [6002], [0], [0], [3], [0], [], [], []
Fri Jan 11 14:19:44 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_ckpt_9579.trc:
ORA-01171: datafile 10 going offline due to error advancing checkpoint
ORA-01122: database file 10 failed verification check
ORA-01110: data file 10: '/data2/DECTR_HIS2.dbf'
ORA-01251: Unknown File Header Version read for file number 10
Fri Jan 11 14:19:59 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_ckpt_9579.trc:
ORA-01171: datafile 31 going offline due to error advancing checkpoint
ORA-01122: database file 31 failed verification check
ORA-01110: data file 31: '/data3/ts2_dpcis.dbf'
ORA-01251: Unknown File Header Version read for file number 31

紧接着，应用系统的某个JOB也由于数据文件无法访问，而开始报错。

Fri Jan 11 14:30:19 2013
Errors in file /oracle/admin/dpdata/bdump/dpdata_j001_12993.trc:
ORA-12012: error on auto execute of job 88
ORA-00376: file 10 cannot be read at this time
ORA-01110: data file 10: '/data2/DECTR_HIS2.dbf'
ORA-06512: at "DECTR.P_MOVE_CONTS_SHIP", line 77
ORA-06512: at line 1

相同的报错一直持续了四十多分钟，之后DBA又再次介入了。但是DBA很奇怪地断然执行了offline这两个数据文件的操作，并在2分多钟之后，又尝试将两个数据文件再次online。而由于文件损坏，自然在online的时候遇到了ORA-1122错误，而无法成功online。

Fri Jan 11 15:16:23 2013
alter database datafile '/data3/ts2_dpcis.dbf' offline
Fri Jan 11 15:16:23 2013
Completed: alter database datafile '/data3/ts2_dpcis.dbf' offline
Fri Jan 11 15:17:05 2013
alter database datafile  '/data2/DECTR_HIS2.dbf'
offline
Fri Jan 11 15:17:05 2013
Completed: alter database datafile  '/data2/DECTR_HIS2.dbf'
offline
Fri Jan 11 15:19:41 2013
alter database datafile '/data3/ts2_dpcis.dbf' online
Fri Jan 11 15:19:41 2013
ORA-1122 signalled during: alter database datafile '/data3/ts2_dpcis.dbf' online...
Fri Jan 11 15:21:10 2013
alter database datafile  '/data2/DECTR_HIS2.dbf' online
Fri Jan 11 15:21:10 2013
ORA-1122 signalled during: alter database datafile  '/data2/DECTR_HIS2.dbf' online...

这才仅仅是噩梦的开始，接下来的一切属于危险动作，请勿轻易模仿。

遇到ORA-1122错误以后，DBA考虑了9秒钟，再次断然地关闭了数据库，并随之又重新启动。由于仅仅是用户表空间数据文件损坏，并且之前也已经被offline了，因此数据库实例毫无障碍地OPEN成功。

Fri Jan 11 15:21:19 2013
Shutting down instance: further logons disabled
Fri Jan 11 15:21:19 2013
Stopping background process QMNC
Fri Jan 11 15:21:19 2013
Stopping background process CJQ0
Fri Jan 11 15:21:21 2013
Stopping background process MMNL
Fri Jan 11 15:21:22 2013
Stopping background process MMON
Fri Jan 11 15:21:23 2013
Shutting down instance (immediate)
……
Fri Jan 11 15:22:59 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 15:23:13 2013
Completed: ALTER DATABASE OPEN

DBA再次尝试online数据文件的操作，同样的ORA-1122错误。

Fri Jan 11 15:23:31 2013
alter database datafile '/data3/ts2_dpcis.dbf' online
Fri Jan 11 15:23:31 2013
ORA-1122 signalled during: alter database datafile '/data3/ts2_dpcis.dbf' online...

考虑了2分半钟之后，DBA也许是想起上午的时候做过控制文件的备份，因此决定进行数据库恢复。重启数据库到nomount状态，并开始进行RECOVER DATABASE USING BACKUP CONTROLFILE，ORA-1507错误的意思是告知如果要使用备份的控制文件进行数据库恢复，那么应该要先使用备份的控制文件将数据库启动到mount状态。

Fri Jan 11 15:25:05 2013
Shutting down instance: further logons disabled
Fri Jan 11 15:25:05 2013
Stopping background process QMNC
Fri Jan 11 15:25:05 2013
Stopping background process CJQ0
Fri Jan 11 15:25:07 2013
Stopping background process MMNL
Fri Jan 11 15:25:08 2013
Stopping background process MMON
Fri Jan 11 15:25:09 2013
Shutting down instance (immediate)
……
Fri Jan 11 15:26:32 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 15:26:46 2013
ALTER DATABASE RECOVER  database using backup controlfile until cancel  
Fri Jan 11 15:26:46 2013
ORA-1507 signalled during: ALTER DATABASE RECOVER  database using backup controlfile    until cancel  ...

DBA于是将数据库启动到mount状态，继续进行数据库恢复。这其中的几个ORA错误都是正常的，ORA-279提示需要一个归档文件来完成恢复，ORA-308提示打不开1_87749_604491553.dbf归档文件，根据前面的告警日志，可以知道实际上87749这个重做日志是当前日志，还没有归档，自然找不到。ORA-1547错误表示恢复已经完成，但是OPEN RESETLOGS的时候仍然要遇到错误。

Fri Jan 11 15:26:56 2013
alter database mount
Fri Jan 11 15:27:00 2013
Setting recovery target incarnation to 2
Fri Jan 11 15:27:00 2013
Successful mount of redo thread 1, with mount id 560899584
Fri Jan 11 15:27:00 2013
Database mounted in Exclusive Mode
Completed: alter database mount
Fri Jan 11 15:27:10 2013
ALTER DATABASE RECOVER  database using backup controlfile until cancel  
Media Recovery Start
 parallel recovery started with 3 processes
ORA-279 signalled during: ALTER DATABASE RECOVER  database using backup controlfile until cancel  ...
Fri Jan 11 15:27:28 2013
ALTER DATABASE RECOVER    CONTINUE DEFAULT  
Fri Jan 11 15:27:28 2013
Media Recovery Log /soft/db_arch/1_87749_604491553.dbf
Errors with log /soft/db_arch/1_87749_604491553.dbf
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...
Fri Jan 11 15:27:28 2013
ALTER DATABASE RECOVER    CONTINUE DEFAULT  
Fri Jan 11 15:27:28 2013
Media Recovery Log /soft/db_arch/1_87749_604491553.dbf
Errors with log /soft/db_arch/1_87749_604491553.dbf
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...
Fri Jan 11 15:27:28 2013
ALTER DATABASE RECOVER CANCEL 
ORA-1547 signalled during: ALTER DATABASE RECOVER CANCEL ...

DBA忽略了这个错误，尝试将数据库打开，很显然会遇到ORA-1589错误，之后又尝试用NORESTLOGS方式OPEN数据库，这也很显然会遇到ORA-1588错误。不完全恢复的数据库必须要以RESETLOGS方式打开。

Fri Jan 11 15:29:52 2013
alter database open
Fri Jan 11 15:29:52 2013
ORA-1589 signalled during: alter database open...
Fri Jan 11 15:30:11 2013
alter database open NORESETLOGS
Fri Jan 11 15:30:11 2013
ORA-1588 signalled during: alter database open NORESETLOGS

之后，DBA作了一个艰难的决定，再次关闭并重启了数据库。又再次尝试相同的OPEN步骤。当然，Oracle也给与了相同的报错。数据库仍然无法打开。至此，数据库无法提供服务已经1个多小时。

Fri Jan 11 15:30:42 2013
Shutting down instance: further logons disabled
Fri Jan 11 15:30:42 2013
Stopping background process CJQ0
Fri Jan 11 15:30:42 2013
Stopping background process MMNL
Fri Jan 11 15:30:43 2013
Stopping background process MMON
Fri Jan 11 15:30:44 2013
Shutting down instance (immediate)
……
Fri Jan 11 15:30:59 2013
Starting ORACLE instance (normal)
……
Fri Jan 11 15:31:08 2013
ALTER DATABASE OPEN
ORA-1589 signalled during: ALTER DATABASE OPEN...
Fri Jan 11 15:31:28 2013
alter database open NORESETLOGS
Fri Jan 11 15:31:28 2013
ORA-1588 signalled during: alter database open NORESETLOGS...
Fri Jan 11 15:31:41 2013
alter database open RESETLOGS
Fri Jan 11 15:31:41 2013
ORA-1122 signalled during: alter database open RESETLOGS...

再接下来，是一团混乱，DBA多次重启数据库，尝试了多种恢复手段。offline数据文件，recover数据文件，recover数据库，online数据文件，再recover，再offline，再open，但是一切尝试都是徒劳的。一直到晚上18:35，在数据库宕机4个多小时以后，开始求助我们帮助其恢复数据库。

Fri Jan 11 15:41:28 2013
alter database datafile '/data2/DECTR_HIS2.dbf' offline
Completed: alter database datafile '/data2/DECTR_HIS2.dbf' offline
Fri Jan 11 15:41:35 2013
alter database open
Fri Jan 11 15:41:35 2013
ORA-1589 signalled during: alter database open...
Fri Jan 11 15:42:20 2013
alter database  open resetlogs
Fri Jan 11 15:42:20 2013
ORA-1245 signalled during: alter database  open resetlogs...
Fri Jan 11 15:43:40 2013
ALTER DATABASE RECOVER  datafile '/data3/ts2_dpcis.dbf'  
Fri Jan 11 15:43:40 2013
Media Recovery Start
Fri Jan 11 15:43:40 2013
Media Recovery failed with error 1610
ORA-283 signalled during: ALTER DATABASE RECOVER  datafile '/data3/ts2_dpcis.dbf'  ...
Fri Jan 11 15:46:09 2013
ALTER DATABASE RECOVER  datafile 10  
Fri Jan 11 15:46:09 2013
Media Recovery Start
Fri Jan 11 15:46:09 2013
Media Recovery failed with error 1610
ORA-283 signalled during: ALTER DATABASE RECOVER  datafile 10  ...
……
Fri Jan 11 16:37:51 2013
ALTER DATABASE RECOVER  database  
Fri Jan 11 16:37:51 2013
Media Recovery Start
Fri Jan 11 16:37:51 2013
Media Recovery failed with error 1610
ORA-283 signalled during: ALTER DATABASE RECOVER  database  ...
Fri Jan 11 16:39:29 2013
ALTER DATABASE RECOVER  database using backup controlfile until cancel  
Fri Jan 11 16:39:29 2013
Media Recovery Start
 parallel recovery started with 3 processes
ORA-279 signalled during: ALTER DATABASE RECOVER  database using backup controlfile until cancel  ...
Fri Jan 11 16:39:43 2013
ALTER DATABASE RECOVER    CANCEL  
Fri Jan 11 16:39:44 2013
ORA-1547 signalled during: ALTER DATABASE RECOVER    CANCEL  ...
Fri Jan 11 16:39:44 2013
ALTER DATABASE RECOVER CANCEL 
ORA-1112 signalled during: ALTER DATABASE RECOVER CANCEL ...
Fri Jan 11 16:40:15 2013
alter database datafile 10 online
Fri Jan 11 16:40:15 2013
Completed: alter database datafile 10 online
Fri Jan 11 16:40:25 2013
alter database datafile 31 online
Completed: alter database datafile 31 online
Fri Jan 11 16:40:47 2013
ALTER DATABASE RECOVER  database using backup controlfile until cancel  
Fri Jan 11 16:40:47 2013
Media Recovery Start
Fri Jan 11 16:40:47 2013
Media Recovery failed with error 1110
ORA-283 signalled during: ALTER DATABASE RECOVER  database using backup controlfile until cancel  ...
Fri Jan 11 16:47:12 2013
WARNING: inbound connection timed out (ORA-3136)
Fri Jan 11 17:44:47 2013
ALTER DATABASE RECOVER  datafile 10  
Fri Jan 11 17:44:47 2013
Media Recovery Start
Fri Jan 11 17:44:47 2013
Media Recovery failed with error 1610
ORA-283 signalled during: ALTER DATABASE RECOVER  datafile 10  ...
Fri Jan 11 17:45:19 2013
ALTER DATABASE RECOVER  database until cancel using backup controlfile  
Fri Jan 11 17:45:19 2013
Media Recovery Start
Fri Jan 11 17:45:19 2013
Media Recovery failed with error 1110
ORA-283 signalled during: ALTER DATABASE RECOVER  database until cancel using backup controlfile  ...
Fri Jan 11 17:46:39 2013
alter database datafile 10 offline
Fri Jan 11 17:46:40 2013
Completed: alter database datafile 10 offline
Fri Jan 11 17:47:18 2013
ALTER DATABASE RECOVER  database until cancel  
Fri Jan 11 17:47:18 2013
Media Recovery Start
Fri Jan 11 17:47:18 2013
Media Recovery failed with error 1610
ORA-283 signalled during: ALTER DATABASE RECOVER  database until cancel  ...
Fri Jan 11 18:11:31 2013
alter database open
Fri Jan 11 18:11:31 2013
ORA-1589 signalled during: alter database open...
Fri Jan 11 18:35:29 2013
Starting ORACLE instance (normal)
Fri Jan 11 18:35:43 2013
alter database open
Fri Jan 11 18:35:43 2013
ORA-1589 signalled during: alter database open...

这是一个没有备份的数据库，实际上如果是存储字系统的问题导致了数据文件损坏，那么可能与DBA的关系并不大，但是在经过一下午的折腾，将一个其实仅仅是坏了2个数据文件而可以轻松OPEN的数据库恢复到无论如何也无法轻易打开的状态，这就与DBA有很大的关系了。