Mysql

MySQL 隨機崩潰並在日誌中顯示“數據庫未正常關閉”消息

  • August 28, 2016

我遇到了一個問題,我的 MySQL 伺服器無緣無故崩潰並且必須重新啟動。

本質上,錯誤日誌具有如下條目:

131128 12:16:35 mysqld_safe Number of processes running now: 0
131128 12:16:35 mysqld_safe mysqld restarted
131128 12:16:36 [Note] Plugin 'FEDERATED' is disabled.
131128 12:16:37 InnoDB: The InnoDB memory heap is disabled
131128 12:16:37 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131128 12:16:37 InnoDB: Compressed tables use zlib 1.2.3
131128 12:16:37 InnoDB: Using Linux native AIO
131128 12:16:37 InnoDB: Initializing buffer pool, size = 768.0M
131128 12:16:37 InnoDB: Completed initialization of buffer pool
131128 12:16:37 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 5922117901
131128 12:16:37  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 5922118503
131128 12:16:41  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 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 
InnoDB: Apply batch completed
131128 12:16:41  InnoDB: Waiting for the background threads to start
131128 12:16:42 InnoDB: 5.5.32 started; log sequence number 5922118503
131128 12:16:42 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131128 12:16:42 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131128 12:16:42 [Note] Server socket created on IP: '0.0.0.0'.
131128 12:16:43 [Note] Event Scheduler: Loaded 0 events
131128 12:16:43 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131128 13:26:34 mysqld_safe Number of processes running now: 0
131128 13:26:34 mysqld_safe mysqld restarted
131128 13:26:35 [Note] Plugin 'FEDERATED' is disabled.
131128 13:26:35 InnoDB: The InnoDB memory heap is disabled
131128 13:26:35 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131128 13:26:35 InnoDB: Compressed tables use zlib 1.2.3
131128 13:26:35 InnoDB: Using Linux native AIO
131128 13:26:35 InnoDB: Initializing buffer pool, size = 768.0M
131128 13:26:35 InnoDB: Completed initialization of buffer pool
131128 13:26:35 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 5922607951
131128 13:26:35  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 5922608207
131128 13:26:39  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 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 
InnoDB: Apply batch completed
131128 13:26:41 InnoDB: 5.5.32 started; log sequence number 5922608207
131128 13:26:41 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131128 13:26:41 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131128 13:26:41 [Note] Server socket created on IP: '0.0.0.0'.
131128 13:26:42 [Note] Event Scheduler: Loaded 0 events
131128 13:26:42 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131128 19:17:10 mysqld_safe Number of processes running now: 0
131128 19:17:10 mysqld_safe mysqld restarted
131128 19:17:10 [Note] Plugin 'FEDERATED' is disabled.
131128 19:17:10 InnoDB: The InnoDB memory heap is disabled
131128 19:17:10 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131128 19:17:10 InnoDB: Compressed tables use zlib 1.2.3
131128 19:17:10 InnoDB: Using Linux native AIO
131128 19:17:10 InnoDB: Initializing buffer pool, size = 768.0M
131128 19:17:10 InnoDB: Completed initialization of buffer pool
131128 19:17:10 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
131128 19:17:10  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
131128 19:17:22  InnoDB: Waiting for the background threads to start
131128 19:17:23 InnoDB: 5.5.32 started; log sequence number 5923508470
131128 19:17:23 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131128 19:17:23 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131128 19:17:23 [Note] Server socket created on IP: '0.0.0.0'.
131128 19:17:23 [Note] Event Scheduler: Loaded 0 events
131128 19:17:23 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131128 23:48:32 mysqld_safe Number of processes running now: 0
131128 23:48:32 mysqld_safe mysqld restarted
131128 23:48:33 [Note] Plugin 'FEDERATED' is disabled.
131128 23:48:33 InnoDB: The InnoDB memory heap is disabled
131128 23:48:33 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131128 23:48:33 InnoDB: Compressed tables use zlib 1.2.3
131128 23:48:33 InnoDB: Using Linux native AIO
131128 23:48:33 InnoDB: Initializing buffer pool, size = 768.0M
131128 23:48:33 InnoDB: Completed initialization of buffer pool
131128 23:48:33 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 5925065422
131128 23:48:33  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 5925065795
131128 23:48:38  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 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 
InnoDB: Apply batch completed
131128 23:48:39  InnoDB: Waiting for the background threads to start
131128 23:48:40 InnoDB: 5.5.32 started; log sequence number 5925065795
131128 23:48:40 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131128 23:48:40 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131128 23:48:40 [Note] Server socket created on IP: '0.0.0.0'.
131128 23:48:41 [Note] Event Scheduler: Loaded 0 events
131128 23:48:41 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131129 02:06:39 mysqld_safe Number of processes running now: 0
131129 02:06:39 mysqld_safe mysqld restarted
131129  2:06:44 [Note] Plugin 'FEDERATED' is disabled.
131129  2:06:45 InnoDB: The InnoDB memory heap is disabled
131129  2:06:45 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131129  2:06:45 InnoDB: Compressed tables use zlib 1.2.3
131129  2:06:45 InnoDB: Using Linux native AIO
131129  2:06:45 InnoDB: Initializing buffer pool, size = 768.0M
131129  2:06:45 InnoDB: Completed initialization of buffer pool
131129  2:06:45 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 5925464870
131129  2:06:45  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 5925465752
131129  2:06:49  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 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 
InnoDB: Apply batch completed
131129  2:06:52  InnoDB: Waiting for the background threads to start
131129  2:06:53 InnoDB: 5.5.32 started; log sequence number 5925465752
131129  2:06:54 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131129  2:06:54 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131129  2:06:54 [Note] Server socket created on IP: '0.0.0.0'.
131129  2:06:55 [Note] Event Scheduler: Loaded 0 events
131129  2:06:55 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131129 06:23:13 mysqld_safe Number of processes running now: 0
131129 06:23:14 mysqld_safe mysqld restarted
131129  6:23:30 [Note] Plugin 'FEDERATED' is disabled.
131129  6:23:33 InnoDB: The InnoDB memory heap is disabled
131129  6:23:33 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131129  6:23:33 InnoDB: Compressed tables use zlib 1.2.3
131129  6:23:33 InnoDB: Using Linux native AIO
131129  6:23:33 InnoDB: Initializing buffer pool, size = 768.0M
131129  6:23:33 InnoDB: Completed initialization of buffer pool
131129  6:23:34 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 5926929016
131129  6:23:34  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 5926968418
131129  6:23:38  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 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 
InnoDB: Apply batch completed
131129  6:23:39  InnoDB: Waiting for the background threads to start
131129  6:23:40 InnoDB: 5.5.32 started; log sequence number 5926968418
131129  6:23:40 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131129  6:23:40 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131129  6:23:40 [Note] Server socket created on IP: '0.0.0.0'.
131129  6:23:41 [Note] Event Scheduler: Loaded 0 events
131129  6:23:41 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.32-cll'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
131129 06:28:05 mysqld_safe Number of processes running now: 0
131129 06:28:05 mysqld_safe mysqld restarted
131129  6:28:06 [Note] Plugin 'FEDERATED' is disabled.
131129  6:28:06 InnoDB: The InnoDB memory heap is disabled
131129  6:28:06 InnoDB: Mutexes and rw_locks use GCC atomic builtins
131129  6:28:06 InnoDB: Compressed tables use zlib 1.2.3
131129  6:28:06 InnoDB: Using Linux native AIO
131129  6:28:06 InnoDB: Initializing buffer pool, size = 768.0M
131129  6:28:06 InnoDB: Completed initialization of buffer pool
131129  6:28:06 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
131129  6:28:06  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
131129  6:28:07  InnoDB: Waiting for the background threads to start
131129  6:28:08 InnoDB: 5.5.32 started; log sequence number 5926985672
131129  6:28:08 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
131129  6:28:08 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
131129  6:28:08 [Note] Server socket created on IP: '0.0.0.0'.
131129  6:28:11 [Note] Event Scheduler: Loaded 0 events
131129  6:28:11 [Note] /usr/sbin/mysqld: ready for connections.

在網際網路上閱讀有關此問題的資訊,我發現這可能是因為其中一個伺服器數據庫中的數據已損壞。

所以我這樣做了:

  • 添加innodb_force_recovery = 4/etc/my.cnf
  • 重啟了mysql服務
  • 使用轉儲數據庫中的數據mysqldump
  • 停止了mysql服務
  • 備份現有的 InnoDB 日誌/數據文件
  • innodb_force_recovery = 4_/etc/my.cnf
  • 重啟了mysql服務
  • 使用之前創建的轉儲重新創建數據庫並向其添加表對象和數據

但崩潰仍在繼續。

這是我的 /etc/my.cnf 文件的副本:

[mysqld]
tmp_table_size=192M
query_cache_limit=16M
join_buffer_size=64M
max_heap_table_size=192M
query_cache_size=64M
max_allowed_packet=256M
sort_buffer_size=64M
myisam_sort_buffer_size=64M
key_buffer=32M
read_buffer_size=64M
sort_buffer_size=64M

open_files_limit=2090
max_connections=32
wait_timeout=1800
table_cache=6400
thread_cache_size=16
max_connect_errors=999999
query_cache_type=1
max_user_connections=200
interactive_timeout=180
connect_timeout=30
net_read_timeout = 600
net_write_timeout = 600
socket="/var/lib/mysql/mysql.sock"
port=3306
default-storage-engine=InnoDB

log-error="/var/lib/mysql/error.log"
slow_query_log_file="/var/lib/mysql/slow-query.log"
slow_query_log=1
long_query_time=5
general_log_file="/var/lib/mysql/general.log"
general_log=1

innodb_buffer_pool_size=768M
innodb_log_buffer_size=32M
innodb_log_file_size=192M
innodb_additional_mem_pool_size=20M
innodb_data_file_path="ibdata1:32M:autoextend"
innodb_data_home_dir="/var/lib/mysql/"
innodb_fast_shutdown=0
innodb_thread_concurrency=8
innodb_file_per_table=1
innodb_flush_method=O_DIRECT
innodb_flush_log_at_trx_commit=0
;innodb_force_recovery=4

[client]
socket="/var/lib/mysql/mysql.sock"
port=3306

我啟用了正常日誌,但在崩潰時我沒有看到任何特殊查詢始終在執行。

有沒有人有任何進一步的建議?有人告訴我這可能是硬體問題,但我的託管服務提供商說他們看不到任何問題。

最後,只有在更改了我的託管計劃(並遠離 cPanel,這似乎掩蓋了一些日誌記錄)之後,我才能夠看到這個問題。事實證明,記憶體使用量有時會飆升(我猜這是因為 apache 子程序的急劇飆升),這會導致記憶體壓力。記憶體不足的殺手會選擇關閉 mysql,因為它(通常)是系統中最大的記憶體使用者。

所以要修復,我

  • 獲得更多記憶體
  • 微調 Apache 以控制啟動的子程序的數量。

引用自:https://dba.stackexchange.com/questions/54200