I have recently migrated a small data warehouse from a 32-bit windows MySQL 5.5 instance to a much larger MariaDB instance. Overall, the performance improvements have been as expected. However, I am running in to scenarios where the database server restarts and I am not able to identify the bottleneck that caused the crash. Where can I see the lead-up to the crash so that I can appropriately tune the config file?
The setup is a virtual machine as follows:
Below is the output from journalctl -u mariadb --since "2018-11-26 14:00:00" showing the recovery. There is nothing before mariadb.service: main process exited that hints at the reason for the ~15:08:30crash.
Nov 26 15:09:19 NCSQL systemd[1]: mariadb.service: main process exited, code=killed, status=9/KILL
Nov 26 15:09:19 NCSQL systemd[1]: Unit mariadb.service entered failed state.
Nov 26 15:09:19 NCSQL systemd[1]: mariadb.service failed.
Nov 26 15:09:24 NCSQL systemd[1]: mariadb.service holdoff time over, scheduling restart.
Nov 26 15:09:24 NCSQL systemd[1]: Starting MariaDB 10.2.18 database server...
Nov 26 15:09:24 NCSQL systemd[1]: Starting MariaDB 10.2.18 database server...
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] /usr/sbin/mysqld (mysqld 10.2.18-MariaDB) starting as process 8873 ...
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Uses event mutexes
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Compressed tables use zlib 1.2.7
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Using Linux native AIO
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Number of pools: 1
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Using SSE2 crc32 instructions
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Initializing buffer pool, total size = 3G, instances = 8, chunk size = 128M
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Completed initialization of buffer pool
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140320821323520 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Highest supported file format is Barracuda.
Nov 26 15:09:25 NCSQL mysqld[8873]: 2018-11-26 15:09:25 140324770257088 [Note] InnoDB: Starting crash recovery from checkpoint LSN=277791212387
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: 128 out of 128 rollback segments are active.
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: Creating shared tablespace for temporary tables
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: Waiting for purge to start
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] InnoDB: 5.7.23 started; log sequence number 277791212441
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140320398370560 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Plugin 'FEEDBACK' is disabled.
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Recovering after a crash using tc.log
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Starting crash recovery...
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Crash recovery finished.
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140320398370560 [Note] InnoDB: Buffer pool(s) load completed at 181126 15:09:27
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Server socket created on IP: '::'.
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [ERROR] mysqld: Table './mysql/event' is marked as crashed and should be repaired
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [ERROR] mysqld: Table 'event' is marked as crashed and should be repaired
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Warning] Checking table: './mysql/event'
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [ERROR] mysql.event: 1 client is using or hasn't closed the table properly
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324635596544 [Note] Event Scheduler: scheduler thread started with id 6
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Reading of all Master_info entries succeded
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] Added new Master_info '' to hash table
Nov 26 15:09:27 NCSQL mysqld[8873]: 2018-11-26 15:09:27 140324770257088 [Note] /usr/sbin/mysqld: ready for connections.
Nov 26 15:09:27 NCSQL mysqld[8873]: Version: '10.2.18-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
Nov 26 15:09:27 NCSQL systemd[1]: Started MariaDB 10.2.18 database server.
My server.cnf has the following:
[mysqld]
lower_case_table_names=1
event_scheduler=on
max_heap_table_size=4G
key_buffer_size=20M
innodb_buffer_pool_size=3G
sql_mode='STRICT_TRANS_TABLES,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION'
The DB service was being shut down by the Linux OOM killer. Hence no MySQL/MariaDB error log messages are shown.
The following command is helpful to confirm:
# dmesg -T | egrep -i 'killed process'