Mysql Redo log 意外损坏问题的恢复过程

其实这是一个意外的情况,问题也不太复杂,过程是这样的,在max os x中使用 vim工具打开log file 文件,然后转换成16进制显示,原来的目的是仅仅转换为16进制的显示格式,但是却将vim将文件彻底转换为了16进制文件,如果此时数据库比如kill掉,那么正常的启动是不能进行的;下面来重演一下今天遇到的问题:

mysql> show databases;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| sys                |
| test               |
+--------------------+
5 rows in set (0.06 sec)

mysql> use test;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show tables;
+----------------+
| Tables_in_test |
+----------------+
| test           |
+----------------+
1 row in set (0.00 sec)

mysql> desc test;
+-------+--------------+------+-----+---------+-------+
| Field | Type         | Null | Key | Default | Extra |
+-------+--------------+------+-----+---------+-------+
| id    | int(11)      | YES  |     | NULL    |       |
| name  | varchar(200) | YES  |     | NULL    |       |
+-------+--------------+------+-----+---------+-------+
2 rows in set (0.01 sec)

mysql> insert into test values (12,'jjjj');
Query OK, 1 row affected (0.01 sec)
mysql> select * from test;
+------+--------+
| id   | name   |
+------+--------+
|    1 | jjjjjj |
|   12 | jjjj   |
+------+--------+
2 rows in set (0.00 sec)
mysql> exit;

这里使用vim打开redo 文件:

redo12

回车后,可以显示为16进制格式:

redo18

此时的显示是没有问题的,问题是直接重新保存了;此时如果启动数据库无法启动的;

2016-10-18T09:37:51.272392Z 1 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2016-10-18T09:37:51.292530Z 1 [Note] InnoDB: Completed initialization of buffer pool
2016-10-18T09:37:51.388325Z 1 [ERROR] InnoDB: Log file ./ib_logfile0 size 50336847 is not a multiple of innodb_page_size
2016-10-18T09:37:51.388380Z 1 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2016-10-18T09:37:51.701317Z 1 [ERROR] Failed to initialize DD Storage Engine
2016-10-18T09:37:51.701439Z 0 [ERROR] Data Dictionary initialization failed.
2016-10-18T09:37:51.701458Z 0 [ERROR] Aborting
2016-10-18T09:37:51.701478Z 0 [Note] Binlog end
2016-10-18T09:37:51.701506Z 0 [Note] Shutting down plugin 'MyISAM'
2016-10-18T09:37:51.701525Z 0 [Note] Shutting down plugin 'InnoDB'
2016-10-18T09:37:51.701533Z 0 [Note] Shutting down plugin 'CSV'
2016-10-18T09:37:51.701857Z 0 [Note] /Volumes/ssd/hadoop/soft/mysql-8/mysql8/bin/mysqld: Shutdown complete

再转换回来呢?结果是不行的:

redo-19

此时查看文件大小:

redo20

两个文件的大小是不同,所以即使转换回来,也不能与原来的问题完全相同了,所以启动数据库会依旧报相同的错误,那么怎么办呢?实际不复杂,直接删除 原来的日志文件,然后启动数据库:

yc:data yc$ ../mysqlstart start
Starting MySQL
.... SUCCESS! 

成功启动;这里延伸一下,删除redo log后直接启动,数据库会自动重新创建redo 文件;那么问题来了,明明是写入了数据,然后kill掉数据库的,那启动数据库时是需要进行恢复过程的,此时就会用到logfile0 而此时的数据文件是重建的,理论上是无法恢复的,那数据库也就不应该能够打开,可此时打开了那问题出在哪里呢?这里是执行的 kill xxxxx,如果是这样,mysql执行的操作是:

2016-10-19T01:24:38.326833Z 0 [Note] Giving 0 client threads a chance to die gracefully
2016-10-19T01:24:38.326869Z 0 [Note] Shutting down slave threads
2016-10-19T01:24:38.326889Z 0 [Note] Forcefully disconnecting 0 remaining clients
2016-10-19T01:24:38.326903Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2016-10-19T01:24:38.327021Z 0 [Note] InnoDB: FTS optimize thread exiting.
2016-10-19T01:24:38.436183Z 0 [Note] Binlog end
2016-10-19T01:24:38.437720Z 0 [Note] Shutting down plugin 'ngram'
2016-10-19T01:24:38.437751Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2016-10-19T01:24:38.437758Z 0 [Note] Shutting down plugin 'ARCHIVE'
2016-10-19T01:24:38.437763Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2016-10-19T01:24:38.437793Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2016-10-19T01:24:38.437804Z 0 [Note] Shutting down plugin 'MyISAM'
2016-10-19T01:24:38.437827Z 0 [Note] Shutting down plugin 'INNODB_CACHED_INDEXES'
2016-10-19T01:24:38.437832Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2016-10-19T01:24:38.437837Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2016-10-19T01:24:38.437840Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2016-10-19T01:24:38.437844Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2016-10-19T01:24:38.437849Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2016-10-19T01:24:38.437852Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2016-10-19T01:24:38.437856Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2016-10-19T01:24:38.437860Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2016-10-19T01:24:38.437864Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2016-10-19T01:24:38.437868Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2016-10-19T01:24:38.437872Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2016-10-19T01:24:38.437875Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2016-10-19T01:24:38.437879Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2016-10-19T01:24:38.437883Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2016-10-19T01:24:38.437887Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2016-10-19T01:24:38.437891Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2016-10-19T01:24:38.437895Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2016-10-19T01:24:38.437898Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2016-10-19T01:24:38.437902Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2016-10-19T01:24:38.437906Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2016-10-19T01:24:38.437910Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2016-10-19T01:24:38.437914Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2016-10-19T01:24:38.437918Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2016-10-19T01:24:38.437922Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2016-10-19T01:24:38.437926Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2016-10-19T01:24:38.437930Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2016-10-19T01:24:38.437934Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2016-10-19T01:24:38.437938Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2016-10-19T01:24:38.437942Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2016-10-19T01:24:38.437945Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2016-10-19T01:24:38.437949Z 0 [Note] Shutting down plugin 'InnoDB'

所以此时是不会发生,恢复操作的;那么如果直接是 kill -9 呢?

2016-10-19T01:33:37.038483Z 0 [Warning] option 'innodb-buffer-pool-dump-pct': unsigned value 0 adjusted to 1
2016-10-19T01:33:37.038987Z 0 [Note] Plugin 'FEDERATED' is disabled.
2016-10-19T01:33:37.039720Z 1 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-10-19T01:33:37.039732Z 1 [Note] InnoDB: Uses event mutexes
2016-10-19T01:33:37.039737Z 1 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2016-10-19T01:33:37.039741Z 1 [Note] InnoDB: Compressed tables use zlib 1.2.3
2016-10-19T01:33:37.039980Z 1 [Note] InnoDB: Number of pools: 1
2016-10-19T01:33:37.040088Z 1 [Note] InnoDB: Using CPU crc32 instructions
2016-10-19T01:33:37.041305Z 1 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2016-10-19T01:33:37.051868Z 1 [Note] InnoDB: Completed initialization of buffer pool
2016-10-19T01:33:37.071735Z 1 [Note] InnoDB: Log scan progressed past the checkpoint lsn 11088465
2016-10-19T01:33:37.071769Z 1 [Note] InnoDB: Doing recovery: scanned up to log sequence number 11088474
2016-10-19T01:33:37.071999Z 1 [Note] InnoDB: Doing recovery: scanned up to log sequence number 11088474
2016-10-19T01:33:37.072017Z 1 [Note] InnoDB: Database was not shutdown normally!
2016-10-19T01:33:37.072025Z 1 [Note] InnoDB: Starting crash recovery.
2016-10-19T01:33:37.181203Z 1 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2016-10-19T01:33:37.181233Z 1 [Note] InnoDB: Creating shared tablespace for temporary tables
2016-10-19T01:33:37.181999Z 1 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

这时是有恢复过程的;那么如果此时,redo 日志又出现问题呢?

2016-10-19T01:59:50.861261Z 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html for information about forcing recovery.
2016-10-19T01:59:50.861533Z 0 [ERROR] InnoDB: Page [page id: space=30, page number=5] log sequence number 11137168 is in the future! Current system log sequence number 11081880.

此时报错数据库仍然是能够启动的; 关于恢复的过程这里不再多说,将另行总结;

发表评论

电子邮件地址不会被公开。 必填项已用*标注