MySQL Crashes frequently

LawsHosting · Aug 24, 2019

I'm not sure what is going on here... This is an OpenVZ 6 CT that has been running flawlessly for years, however, two days ago MySQL started to crash/restart at random intervals. A client mucked up their wordpress database, so I reimported a .sql backup via phpmyadmin.... This is when this weird situation started to happen....

I thought it was a memory/vswap issue, however, a reboot of the CT didn't help, MySQL crashed three hours later...

Here's some of the log

Code:

2019-08-24 06:37:07 2076 [Note] IPv6 is available.2019-08-24 06:37:07 2076 [Note]   - '::' resolves to '::';
2019-08-24 06:37:07 2076 [Note] Server socket created on IP: '::'.
2019-08-24 06:37:07 2076 [Warning] 'user' entry 'root@xxxxxxxxx' ignored in --skip-name-resolve mode.
2019-08-24 06:37:07 2076 [Warning] 'user' entry '@xxxxxxxxxxx' ignored in --skip-name-resolve mode.
2019-08-24 06:37:07 2076 [Warning] 'proxies_priv' entry '@ root@xxxxxxx' ignored in --skip-name-resolve mode.
2019-08-24 06:37:07 2076 [Note] Event Scheduler: Loaded 0 events
2019-08-24 06:37:07 2076 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.6.12'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
190824 08:55:03 mysqld_safe Number of processes running now: 0
190824 08:55:03 mysqld_safe mysqld restarted
2019-08-24 08:55:04 15986 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:55:05 15986 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:55:05 15986 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:55:05 15986 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:55:05 15986 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:55:05 15986 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:55:05 15986 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:55:05 15986 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 08:55:10 15986 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 08:55:10 15986 [Note] InnoDB: Highest supported file format is Barracuda.
2019-08-24 08:55:11 15986 [Note] InnoDB: The log sequence numbers 1150586314715 and 1150586314715 in ibdata files do not match the log sequence number 1150587701549 in the ib_logfiles!
2019-08-24 08:55:11 15986 [Note] InnoDB: Database was not shutdown normally!
2019-08-24 08:55:11 15986 [Note] InnoDB: Starting crash recovery.
2019-08-24 08:55:11 15986 [Note] InnoDB: Reading tablespace information from the .ibd files...
2019-08-24 08:55:11 15986 [Note] InnoDB: Restoring possible half-written data pages
2019-08-24 08:55:11 15986 [Note] InnoDB: from the doublewrite buffer...
190824 08:55:12 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 08:56:05 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 08:56:05 16983 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:56:05 16983 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:56:05 16983 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:56:05 16983 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:56:05 16983 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:56:05 16983 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:56:05 16983 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:56:05 16983 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 08:56:07 16983 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 08:56:07 16983 [Note] InnoDB: Highest supported file format is Barracuda.
190824 08:56:07 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 08:57:02 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 08:57:02 18084 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:57:02 18084 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:57:02 18084 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:57:02 18084 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:57:02 18084 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:57:02 18084 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:57:02 18084 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:57:02 18084 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 08:57:04 18084 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 08:57:04 18084 [Note] InnoDB: Highest supported file format is Barracuda.
190824 08:57:05 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 08:57:17 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 08:57:18 18944 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:57:18 18944 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:57:18 18944 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:57:18 18944 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:57:18 18944 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:57:18 18944 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:57:18 18944 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:57:18 18944 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 08:57:19 18944 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 08:57:19 18944 [Note] InnoDB: Highest supported file format is Barracuda.
190824 08:57:19 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 08:58:05 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 08:58:06 19878 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:58:06 19878 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:58:06 19878 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:58:06 19878 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:58:06 19878 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:58:06 19878 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:58:06 19878 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:58:06 19878 [Note] InnoDB: Initializing buffer pool, size = 6.0G
190824 08:58:08 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 08:59:05 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 08:59:05 20907 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 08:59:05 20907 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 08:59:05 20907 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 08:59:05 20907 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 08:59:05 20907 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 08:59:05 20907 [Note] InnoDB: Using Linux native AIO
2019-08-24 08:59:05 20907 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 08:59:05 20907 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 08:59:06 20907 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 08:59:06 20907 [Note] InnoDB: Highest supported file format is Barracuda.
190824 08:59:07 mysqld_safe mysqld from pid file /usr/local/mysql/data/server5.pid ended
190824 09:00:03 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2019-08-24 09:00:03 22083 [Warning] You need to use --log-bin to make --binlog-format work.
2019-08-24 09:00:03 22083 [Note] Plugin 'FEDERATED' is disabled.
2019-08-24 09:00:03 22083 [Note] InnoDB: The InnoDB memory heap is disabled
2019-08-24 09:00:03 22083 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-08-24 09:00:03 22083 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-08-24 09:00:03 22083 [Note] InnoDB: Using Linux native AIO
2019-08-24 09:00:03 22083 [Note] InnoDB: Using CPU crc32 instructions
2019-08-24 09:00:03 22083 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2019-08-24 09:00:04 22083 [Note] InnoDB: Completed initialization of buffer pool
2019-08-24 09:00:04 22083 [Note] InnoDB: Highest supported file format is Barracuda.
2019-08-24 09:00:04 22083 [Note] InnoDB: The log sequence numbers 1150586314715 and 1150586314715 in ibdata files do not match the log sequence number 1150587701549 in the ib_logfiles!
2019-08-24 09:00:04 22083 [Note] InnoDB: Database was not shutdown normally!
2019-08-24 09:00:04 22083 [Note] InnoDB: Starting crash recovery.
2019-08-24 09:00:04 22083 [Note] InnoDB: Reading tablespace information from the .ibd files...
2019-08-24 09:00:05 22083 [Note] InnoDB: Restoring possible half-written data pages
2019-08-24 09:00:05 22083 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Last MySQL binlog file position 0 641159340, file name mysql-bin.000364
2019-08-24 09:00:06 22083 [Note] InnoDB: 128 rollback segment(s) are active.
2019-08-24 09:00:06 22083 [Note] InnoDB: Waiting for purge to start
2019-08-24 09:00:06 22083 [Note] InnoDB: 5.6.12 started; log sequence number 1150587701549
2019-08-24 09:00:06 22083 [Note] Server hostname (bind-address): '*'; port: 3306
2019-08-24 09:00:06 22083 [Note] IPv6 is available.
2019-08-24 09:00:06 22083 [Note]   - '::' resolves to '::';
2019-08-24 09:00:06 22083 [Note] Server socket created on IP: '::'.
2019-08-24 09:00:06 22083 [Warning] 'user' entry 'root@xxxxxxxs' ignored in --skip-name-resolve mode.
2019-08-24 09:00:06 22083 [Warning] 'user' entry '@xxxxxxxx' ignored in --skip-name-resolve mode.
2019-08-24 09:00:06 22083 [Warning] 'proxies_priv' entry '@ root@xxxxxxxxx' ignored in --skip-name-resolve mode.
2019-08-24 09:00:06 22083 [Note] Event Scheduler: Loaded 0 events
2019-08-24 09:00:06 22083 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.6.12'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution

Any ideas of what is going on? And to debug further?

urgido · Aug 24, 2019

Is an innoDB database?

LawsHosting · Aug 24, 2019

Most are InnoDB these days.......

Now, I really think it could be php-fpm, I know the size in DA's Services section isn't a reflect on real memory, but most of the time, the processes grow and grow..... Leading to show 14Gig, whereas the CT only has 12Gb memory, and 2Gb vSwap...... Yes, it's a busy CT, but it's been ok (well, load is high with 4 vCores) for years...... Maybe the client's sites visits are now too big for the CT now.

What is interesting, when MySQL crashes, sometimes it doesn't come back up. However, once I restart the php-fpm processes, MySQL instantly comes back up.

Like I say, I only noticed this behaviour a few hours after I imported back a backup database.

MySQL Crashes frequently

LawsHosting

Verified User

urgido

Verified User

LawsHosting

Verified User