閱讀目錄(Content)php
基於MySQL5.7版本,5.7版本在恢復過程作了優化,本文描述不考慮以前版本。html
數據庫關閉只有2種狀況,正常關閉,非正常關閉(包括數據庫實例crash及服務器crash)。mysql
正常關閉狀況,全部buffer pool裏邊的髒頁都會都會刷新一遍到磁盤,同時記錄最新LSN到ibdata文件的第一個page中。而非正常關閉來不及作這些操做,也就是沒及時把髒數據flush到磁盤,也沒有記錄最新LSN到ibdata file。sql
當咱們重啓數據庫實例的時候,數據庫作2個階段性操做:redo log處理,undo log及binlog 處理。數據庫
恢復的過程當中,注意兩個點:打開ibd文件形式,讀取數據庫到buffer pool的改進。vim
根據hash表中的相應信息讀取數據頁, 讀數據頁的時候,5.7以前版本採用把全部表空間都打開,全部表格僅執行ReadOnly,5.7版本作了優化,新增了 MLOG_FILE_NAME 記錄在checkpoint以後,全部被修改過的信息,根據這些信息,在恢復過程當中,只須要打開相應的ibd文件便可,不涉及恢復的表格支持正常DML跟DDL操做,涉及恢復的表格則僅執行ReadOnly功能。安全
當把數據頁讀取到buffer pool中,以往版本是隻讀取對應的單個頁面,而如今的是直接讀取與該頁面相鄰的32個data page 也一塊兒加載的buffer pool,由於一個數據頁的修改,可能周圍的頁面也被修改,一次性讀取,能夠避免後面根據hash表中再從新讀取其相鄰的頁面。服務器
上一階段中,把redo log中的操做都apply到數據頁中,可是對於prepare狀態的事務卻尚未進行回滾處理,這個階段則是針對prepare狀態的事務進行處理,須要使用到binlog和undo log。app
整個恢復過程,能夠參考下來自 www.sysdb.cn 網站做者 boyce 畫的說明圖,圖片版權屬於該做者,本處僅爲引用分享給你們,做圖很詳細,一言不合開源碼分析!遺憾的是,做者只寫了2篇博文就中止更新了,心疼默哀十分鐘.....socket
數據庫關閉的時候,innodb須要完成全部full purge何insert buffer操做,這須要一些時間,甚至幾個小時完成
這裏注意,數字越小,則忽略檢查的內容越少,每一個大的數字都包含了前面小數字忽略檢查的內容。當參數設置大於0後,能夠對錶格進行DML操做,可是DDL操做時不容許的。
當innodb_force_recovery 值爲1-3時,僅容許SELECT TABLE ,DROP or CREATE tables;innodb_force_recovery 值爲>=4時,5.7.17以前版本支持DROP TABLE,5.7.18後版本不支持。
參數說明以下圖:
測試內容:
begin;insert into orders select * from orders.orders limit 100000;
插入結束後不提交事務,執行 kill mysql進程
tailf error.log查看
配置說明:異常中止DB服務時,不須要完成 full purge 和 insert buffer 操做,可是緩衝池的髒數據須要刷新到磁盤;服務啓動的時候,作全部須要的檢查跟事務操做。
1 #1 tailf error.log查看mysql錯誤日誌,動態滾動查看 2 mysql> show global variables like 'log_error'; 3 tailf /data/mysql/mysql3310/data/error.log 4 5 #2 測試庫中開啓事務,insert 10w行記錄,不提交事務 6 mysql> begin;insert into orders select * from orders.orders limit 100000; 7 Query OK, 0 rows affected (0.00 sec) 8 9 Query OK, 100000 rows affected (37.55 sec) 10 Records: 100000 Duplicates: 0 Warnings: 0 11 12 #3 查找mysql進程號,殺進程 13 [root@localhost opt]# ps axu | grep mysql 14 [root@localhost opt]# kill -9 mysql的進程號 15 16 #4 啓動mysql服務 17 mysqld --defaults-file=/data/mysql/mysql3310/mysql3310.cnf & 18 19 #5 到tailf error.log窗口查看錯誤
啓動mysqld進程
2017-03-16T16:28:13.812074Z 0 [Note] mysqld (mysqld 5.7.14-log) starting as process 28091 ...
讀取ibdata的LSN
讀取redo文件的checkpoint,從該點的LSN開始查找MLOG_CHECKPOINT
發現MLOG_CHECKPOINT日誌,提示:Database was not shutdown normally !
2017-03-16T16:28:16.572276Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 898634772645
2017-03-16T16:28:16.572418Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898634772654
2017-03-16T16:28:16.693771Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898634772654
2017-03-16T16:28:16.693880Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-03-16T16:28:16.693913Z 0 [Note] InnoDB: Starting crash recovery.
檢測須要重作跟回滾的事務
因爲沒有須要redo的事務,可是有undo事務,開始undo操做
加載redo log中的96個系統回滾段 rollbak segment,32個不須要redo 的臨時表空間的回滾段
2017-03-16T16:28:17.360953Z 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 100000 row operations to undo
獲取binlog回滾xid列表,結合undo log作回滾操做
2017-03-16T16:28:17.361122Z 0 [Note] InnoDB: Trx id counter is 5716480
2017-03-16T16:28:17.625441Z 0 [Note] InnoDB: Last MySQL binlog file position 0 37774, file name bin_log.000016
2017-03-16T16:28:17.787684Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
2017-03-16T16:28:17.788022Z 0 [Note] InnoDB: Rolling back trx with id 5715975, 100000 rows to undo
啓動innodb,加載buffer pool
2017-03-16T16:28:17.838323Z 0 [Note] InnoDB: Waiting for purge to start
2017-03-16T16:28:18.015792Z 0 [Note] InnoDB: 5.7.14 started; log sequence number 898634772654
mysqld正常運行提供用戶使用
2017-03-16T16:28:18.772035Z 0 [Note] mysqld: ready for connections.
Version: '5.7.14-log' socket: '/tmp/mysql3310.sock' port: 3310 MySQL Community Server (GPL)
這個時候,recovery可能還沒結束,好比這個例子中,recovery就還在進行,其涉及的表僅提供ReadOnly操做,其餘表格可正常操做 ,慢慢恢復,最後undo回滾事務完成,Rollback of non-prepared transactions completed
2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 1002017-03-16T16:29:24.353056Z 0 [Note] InnoDB: Rollback of trx with id 5715975 completed
2017-03-16T16:29:24.353267Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed
整個過程16:28:13啓動,16:28:18 DB提供部分服務,16:29:24全庫恢復,db部分提供服務耗時5s,全庫提供服務耗時71s 。
1 2017-03-16T16:28:13.812074Z 0 [Note] mysqld (mysqld 5.7.14-log) starting as process 28091 ... 2 2017-03-16T16:28:14.250956Z 0 [Note] InnoDB: PUNCH HOLE support not available 3 2017-03-16T16:28:14.251212Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 4 2017-03-16T16:28:14.251311Z 0 [Note] InnoDB: Uses event mutexes 5 2017-03-16T16:28:14.251359Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier 6 2017-03-16T16:28:14.251401Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3 7 2017-03-16T16:28:14.251311Z 0 [Note] InnoDB: Uses event mutexes 8 2017-03-16T16:28:14.251359Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier 9 2017-03-16T16:28:14.251401Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3 10 2017-03-16T16:28:14.251440Z 0 [Note] InnoDB: Using Linux native AIO 11 2017-03-16T16:28:14.252570Z 0 [Note] InnoDB: Number of pools: 1 12 2017-03-16T16:28:14.253079Z 0 [Note] InnoDB: Not using CPU crc32 instructions 13 2017-03-16T16:28:14.258163Z 0 [Note] InnoDB: Initializing buffer pool, total size = 9G, instances = 8, chunk size = 128M 14 2017-03-16T16:28:16.101862Z 0 [Note] InnoDB: Completed initialization of buffer pool 15 2017-03-16T16:28:16.406890Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 16 2017-03-16T16:28:16.447145Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 17 2017-03-16T16:28:16.572276Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 898634772645 18 2017-03-16T16:28:16.572418Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898634772654 19 2017-03-16T16:28:16.693771Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898634772654 20 2017-03-16T16:28:16.693880Z 0 [Note] InnoDB: Database was not shutdown normally! 21 2017-03-16T16:28:16.693913Z 0 [Note] InnoDB: Starting crash recovery. 22 2017-03-16T16:28:17.360953Z 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 100000 row operations to undo 23 2017-03-16T16:28:17.361122Z 0 [Note] InnoDB: Trx id counter is 5716480 24 2017-03-16T16:28:17.625441Z 0 [Note] InnoDB: Last MySQL binlog file position 0 37774, file name bin_log.000016 25 2017-03-16T16:28:17.787684Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions 26 2017-03-16T16:28:17.788022Z 0 [Note] InnoDB: Rolling back trx with id 5715975, 100000 rows to undo 27 28 InnoDB: Progress in percents: 12017-03-16T16:28:17.788272Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 29 2017-03-16T16:28:17.788603Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 30 2017-03-16T16:28:17.788603Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 31 2017-03-16T16:28:17.788937Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 32 2017-03-16T16:28:17.831078Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 33 2017-03-16T16:28:17.834673Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 34 2017-03-16T16:28:17.834822Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 35 2017-03-16T16:28:17.838323Z 0 [Note] InnoDB: Waiting for purge to start 36 2017-03-16T16:28:18.015792Z 0 [Note] InnoDB: 5.7.14 started; log sequence number 898634772654 37 2017-03-16T16:28:18.018091Z 0 [Note] InnoDB: Loading buffer pool(s) from /data/mysql/mysql3310/data/ib_buffer_pool 38 2017-03-16T16:28:18.018464Z 0 [Note] Plugin 'FEDERATED' is disabled. 39 2017-03-16T16:28:18.119301Z 0 [Note] Recovering after a crash using /data/mysql/mysql3310/logs/bin_log 40 2017-03-16T16:28:18.119442Z 0 [Note] Starting crash recovery... 41 2017-03-16T16:28:18.119442Z 0 [Note] Starting crash recovery... 42 2017-03-16T16:28:18.119624Z 0 [Note] Crash recovery finished. 43 2017-03-16T16:28:18.203723Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key 44 2017-03-16T16:28:18.203835Z 0 [Note] Server hostname (bind-address): '*'; port: 3310 45 2017-03-16T16:28:18.204188Z 0 [Note] IPv6 is available. 46 2017-03-16T16:28:18.204339Z 0 [Note] - '::' resolves to '::'; 47 2017-03-16T16:28:18.204667Z 0 [Note] Server socket created on IP: '::'. 48 2017-03-16T16:28:18.377789Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode. 49 2017-03-16T16:28:18.378054Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode. 50 2017-03-16T16:28:18.378170Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode. 51 2017-03-16T16:28:18.392680Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode. 52 2017-03-16T16:28:18.771122Z 0 [Note] Event Scheduler: Loaded 0 events 53 2017-03-16T16:28:18.772035Z 0 [Note] mysqld: ready for connections. 54 Version: '5.7.14-log' socket: '/tmp/mysql3310.sock' port: 3310 MySQL Community Server (GPL) 55 2017-03-16T16:28:21.404135Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170317 0:28:21 56 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 1002017-03-16T16:29:24.353056Z 0 [Note] InnoDB: Rollback of trx with id 5715975 completed 57 2017-03-16T16:29:24.353267Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed
配置說明:異常中止DB服務時,不須要完成full purge和insert buffer操做,可是緩衝池的髒數據須要刷新到磁盤;服務啓動的時候,忽略檢查corrupt頁,也阻止主線程的運行,而且不執行事務回滾操做。
當innodb_force_recovery 值爲1-3時,容許SELECT TABLE ,DROP or CREATE tables;innodb_force_recovery 值爲>=4時,5.7.17以前版本支持DROP TABLE,5.7.18後版本不支持。
這個配置適用於這種狀況:有某些大表執行alter或者大量數據修改操做生成大量undo宕機,那麼這個狀況下,能夠進入cnf配置文件修改innodb_force_recovery=3,而後把再作undo操做的表格數據導出來或者利用備份文件的數據,再drop掉這個表格,進入cnf配置文件,修改參數爲0,重啓DB服務,會發現,rollback過程很是快執行結束,由於找不到對應表格,因此rollback很是快。
Tips: 如何查找在undo操做的表格?
數據庫crash後,第一個正常啓動恢復鏈接,連進數據庫裏邊,操做全部表格,不支持insert update 的表格都屬於正在undo的表。
1 #1 tailf error.log查看mysql錯誤日誌,動態滾動查看 2 mysql> show global variables like 'log_error'; 3 tailf /data/mysql/mysql3310/data/error.log 4 5 #2 測試庫中開啓事務,insert 10w行記錄,不提交事務 6 mysql> begin;insert into orders select * from orders.orders limit 100000; 7 Query OK, 0 rows affected (0.00 sec) 8 9 Query OK, 100000 rows affected (37.55 sec) 10 Records: 100000 Duplicates: 0 Warnings: 0 11 12 #3 查找mysql進程號,殺進程 13 [root@localhost opt]# ps axu | grep mysql 14 [root@localhost opt]# kill -9 mysql的進程號 15 16 #4 在cnf文件中指定innodb_force_recovery=3,啓動服務,檢查是否修改爲功 17 [root@localhost ~]# vim /data/mysql/mysql3310.cnf 18 #添加innodb_force_recovery參數設置 19 [mysqld] 20 innodb_force_recovery=3 21 22 #5 啓動mysql服務 23 [root@localhost ~]# mysqld --defaults-file=/data/mysql/mysql3310.cnf & 24 25 #6 到tailf error.log窗口查看錯誤 26 #發現沒有進行undo操做,同時全庫僅支持select drop create,不支持其餘全部操做
啓動mysqld進程
2017-03-17T15:12:14.317391Z 0 [Note] mysqld (mysqld 5.7.14-log) starting as process 32094 ...
讀取ibdata的LSN
讀取redo文件的checkpoint,從該點的LSN開始查找MLOG_CHECKPOINT
發現MLOG_CHECKPOINT日誌,提示:Database was not shutdown normally !
2017-03-17T15:12:16.478403Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 898935661420
2017-03-17T15:12:16.478579Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898935661429
2017-03-17T15:12:16.532923Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 898935661429
2017-03-17T15:12:16.533063Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-03-17T15:12:16.533105Z 0 [Note] InnoDB: Starting crash recovery.
檢測須要重作跟回滾的事務
因爲沒有須要redo的事務,可是有undo事務,開始undo操做
加載redo log中的96個系統回滾段 rollbak segment,32個不須要redo 的臨時表空間的回滾段
2017-03-17T15:12:17.052734Z 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 100000 row operations to undo
獲取binlog回滾xid列表,可是這裏注意,沒有作 回滾操做
2017-03-17T15:12:17.053009Z 0 [Note] InnoDB: Trx id counter is 5718016
2017-03-17T15:12:17.321987Z 0 [Note] InnoDB: Last MySQL binlog file position 0 37774, file name bin_log.000016
啓動innodb,加載buffer pool ,警告當前 innodb_force_recovery 設置爲3
2017-03-17T15:12:17.518732Z 0 [Note] InnoDB: 5.7.14 started; log sequence number 898935661429
2017-03-17T15:12:17.518789Z 0 [Note] InnoDB: !!! innodb_force_recovery is set to 3 !!!
2017-03-17T15:12:17.519305Z 0 [Note] InnoDB: Loading buffer pool(s) from /data/mysql/mysql3310/data/ib_buffer_pool
mysqld正常運行提供用戶使用,可是,全庫僅提供readonly
2017-03-17T15:12:18.521680Z 0 [Note] mysqld: ready for connections.
Version: '5.7.14-log' socket: '/tmp/mysql3310.sock' port: 3310 MySQL Community Server (GPL)
2017-03-17T15:13:03.125686Z 2 [ERROR] InnoDB: innodb_force_recovery is on. We do not allow database modifications by the user. Shut down mysqld and edit my.cnf to set innodb_force_recovery=0
整個過程15:12:14啓動,15:12:18 DB提供部分服務,耗時4s。可是因爲沒有作undo操做,錯誤日誌提醒 We do not allow database modifications by the user. 不支持當前用戶進行數據庫修改操做,僅支持select table,drop table,create table操做,其餘全部操做都不支持。
這種狀況下啓動數據庫後,能夠支持你dump出正在作undo的表格數據,而後drop掉它,若是你有備份文件恢復,那麼則不須要dump,直接drop,而後修改cnf配置文件,設置innodb_force_recovery=0 ,重啓數據庫服務,這個時候,innodb 的undo recovery很是快,由於找不到對應的表格操做,因此都是直接挑過處理。正常恢復後,趕忙把drop掉的表格從備份文件或者dump出來的sql文件中恢復回來。注意注意!!!!這種狀況要權衡利弊,從時間耗時跟操做安全數據安全考慮,是undo recovery快仍是你如此操做快,而後必定必定要跟你的上級或者領導報備操做的風險性,不要默默幹,要報告!!!
實驗2 詳細error log記錄
參考文章:
https://dev.mysql.com/doc/refman/5.7/en/innodb-parameters.html
http://www.sysdb.cn/index.php/2016/01/14/innodb-recovery/?utm_source=tuicool&utm_medium=referral