MySQL crashes randomly with “Database was not shut down normally” message in log

dba.stackexchange https://dba.stackexchange.com/questions/54200

  •  02-11-2019
  •  | 
  •  

Вопрос

I am having an issue where, for no apparent reason, my MySQL server crashes and has to restart.

Essentially, the error log has entries like this:

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.

Reading about on this issue on the internet, I saw that this could happen because data in one of the server's database is corrupted.

So I did this:

  • added innodb_force_recovery = 4 to /etc/my.cnf
  • restarted the mysql service
  • dumped the data in the database using mysqldump
  • stopped the mysql service
  • backed up existing InnoDB log/data files
  • removed the innodb_force_recovery = 4 line from /etc/my.cnf
  • restarted the mysql service
  • re-created the database and added table objects and data to it, using the dump created earlier

But the crashes still continue.

Here is a copy of my /etc/my.cnf file:

[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

I have the general log enabled, but I don't see any special query consistently being run at the time of the crash.

Does anyone have any further suggestions? I have been told it might be a hardware issue, but my hosting provider says they cannot see any problems.

Нет правильного решения

Лицензировано под: CC-BY-SA с атрибуция
Не связан с dba.stackexchange
scroll top