前段時間，有測試人員聯系我，尋求幫助，讓我幫忙看看，測試環境的一臺mysql數據庫不斷的重啟，導致他們的測試無法進行，時間拖的長了，會影響上線進度。

下面就來說說現象

在一個測試環境，mysql5.7部署在centos7.4的系統上，測試人員用LoadRunner進行應用的一個壓測測試，壓測并發為128，啟動LoadRunner過幾秒，LoadRunner日志就報錯，顯示mysql服務斷開了，過幾秒又恢復，然后又斷開，異常詭異。

排查定位

于是就登錄到服務器，看一下數據庫服務器的內存，內存已經用完了，緊接著就看centos的系統日志(/var/log/messages)，在這個日志里發現mysql服務因為OOM，導致進程被系統給kill掉了，然后因為mysql服務有守護進程存在，又被自動啟動了。

一個經驗豐富的mysql數據庫運維人員，應該很快就知道什么原因導致OOM了。
第一：mysql數據庫的buffer pool內存參數配置不合理
第二：mysql數據庫的session初始化內存參數配置不合理
第三：數據庫連接總數配置不合理

測試環境的數據庫服務器內存為4G，在這里就不談，為什么測試人員要在這個服務器上做壓測，其實做應用壓測，應該要用準用的壓測環境，而不是隨便找個環境就壓測，不展開說了。

模擬復盤

測試環境
mysql5.7，centos7.7，內存2G

為了更好的模擬復盤上述故障，這里關閉掉模擬環境的swap，關閉步驟如下所示

[root@localhost data]# free -m total used free shared buff/cache availableMem: 2124 565 640 9 917 1398Swap: 2047 0 2047[root@localhost data]# swapon -s文件名 類型 大小 已用 權限/dev/dm-1 partition 2097148 264 -2[root@localhost data]# swapoff /dev/dm-1[root@localhost data]# free -m total used free shared buff/cache availableMem: 2124 254 944 9 925 1709Swap: 0 0 0

從上面free -m結果中，可以看到swap已經變成0了。

釋放cache占用的內存

[root@localhost data]# sync[root@localhost data]# echo 1 > /proc/sys/vm/drop_caches ; [root@localhost data]# free -m total used free shared buff/cache availableMem: 2124 254 1784 9 84 1748Swap: 0 0 0

可以看到目前剩余的內存為1784M，mysql數據庫占用內存主要有2大塊，第一是：buffer pool占用，第二是：初始化連接占用的內存

在這里設置mysql的buffer pool為1500M，會話的參數設置如下

read_buffer_size = 32Mread_rnd_buffer_size = 32Msort_buffer_size = 32Mtmp_table_size = 32Mmax_heap_table_size=32Mjoin_buffer_size=32M

然后5個連接，開始做大查詢操作，沒過多久，mysql進程就因為OOM被kill了

Aug 31 05:37:40 localhost kernel: Out of memory: Kill process 2534 (mysqld) score 658 or sacrifice childAug 31 05:37:40 localhost kernel: Killed process 2534 (mysqld), UID 1001, total-vm:1825792kB, anon-rss:654388kB, file-rss:0kB, shmem-rss:0kB

mysql守護進程就開始啟動mysql服務

/u02/mysql/bin/mysqld_safe: 行 198: 2534 已殺死 nohup /u02/mysql/bin/mysqld --defaults-file=/u02/conf/my3308.cnf --basedir=/u02/mysql --datadir=/u02/data/3308 --plugin-dir=/u02/mysql/lib/plugin --user=mysql --log-error=/u02/log/3308/error.log --open-files-limit=65535 --pid-file=/u02/run/3308/mysqld.pid --socket=/u02/run/3308/mysql.sock --port=3308 < /dev/null > /dev/null 2>&12020-08-30T21:37:40.375749Z mysqld_safe Number of processes running now: 02020-08-30T21:37:40.407781Z mysqld_safe mysqld restarted2020-08-30T21:37:40.666886Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).2020-08-30T21:37:40.667059Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled2020-08-30T21:37:40.667112Z 0 [Note] /u02/mysql/bin/mysqld (mysqld 5.7.26-log) starting as process 2954 ...2020-08-30T21:37:40.782412Z 0 [Warning] InnoDB: Using innodb_file_format is deprecated and the parameter may be removed in future releases. See http://dev.mysql.com/doc/refman/5.7/en/innodb-file-format.html2020-08-30T21:37:40.782684Z 0 [Note] InnoDB: PUNCH HOLE support available2020-08-30T21:37:40.782729Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins2020-08-30T21:37:40.782754Z 0 [Note] InnoDB: Uses event mutexes2020-08-30T21:37:40.782772Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier2020-08-30T21:37:40.782788Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.112020-08-30T21:37:40.782841Z 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB2020-08-30T21:37:40.784518Z 0 [Note] InnoDB: Number of pools: 12020-08-30T21:37:40.784865Z 0 [Note] InnoDB: Using CPU crc32 instructions2020-08-30T21:37:40.789314Z 0 [Note] InnoDB: Initializing buffer pool, total size = 512M, instances = 1, chunk size = 128M2020-08-30T21:37:40.834948Z 0 [Note] InnoDB: Completed initialization of buffer pool2020-08-30T21:37:40.843612Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().2020-08-30T21:37:40.859028Z 0 [Note] InnoDB: Highest supported file format is Barracuda.2020-08-30T21:37:40.863176Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 57073942292020-08-30T21:37:40.863221Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 57073942382020-08-30T21:37:40.863231Z 0 [Note] InnoDB: Database was not shutdown normally!2020-08-30T21:37:40.863239Z 0 [Note] InnoDB: Starting crash recovery.2020-08-30T21:37:40.901955Z 0 [Note] InnoDB: Last MySQL binlog file position 0 43848, file name binlog.0000252020-08-30T21:37:41.075805Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"2020-08-30T21:37:41.075860Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables2020-08-30T21:37:41.075952Z 0 [Note] InnoDB: Setting file '/u02/log/3308/iblog/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...2020-08-30T21:37:41.254016Z 0 [Note] InnoDB: File '/u02/log/3308/iblog/ibtmp1' size is now 12 MB.2020-08-30T21:37:41.255390Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.2020-08-30T21:37:41.255421Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.2020-08-30T21:37:41.256171Z 0 [Note] InnoDB: Waiting for purge to start2020-08-30T21:37:41.307237Z 0 [Note] InnoDB: 5.7.26 started; log sequence number 57073942382020-08-30T21:37:41.308291Z 0 [Note] Plugin 'FEDERATED' is disabled.2020-08-30T21:37:41.310625Z 0 [Note] InnoDB: Loading buffer pool(s) from /u02/log/3308/iblog/ib_buffer_pool2020-08-30T21:37:41.310785Z 0 [Note] InnoDB: Buffer pool(s) load completed at 200831 5:37:41 (/u02/log/3308/iblog/ib_buffer_pool was empty)2020-08-30T21:37:41.314568Z 0 [Note] Recovering after a crash using /u02/log/3308/binlog/binlog2020-08-30T21:37:41.314730Z 0 [Note] Starting crash recovery...2020-08-30T21:37:41.314842Z 0 [Note] Crash recovery finished.2020-08-30T21:37:41.346280Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.2020-08-30T21:37:41.346337Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.2020-08-30T21:37:41.349079Z 0 [Warning] CA certificate ca.pem is self signed.2020-08-30T21:37:41.349341Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.2020-08-30T21:37:41.350297Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 33082020-08-30T21:37:41.350399Z 0 [Note] - '0.0.0.0' resolves to '0.0.0.0';2020-08-30T21:37:41.350475Z 0 [Note] Server socket created on IP: '0.0.0.0'.2020-08-30T21:37:41.376794Z 0 [Note] Failed to start slave threads for channel ''2020-08-30T21:37:41.397237Z 0 [Note] Event Scheduler: Loaded 0 events2020-08-30T21:37:41.397480Z 0 [Note] /u02/mysql/bin/mysqld: ready for connections.Version: '5.7.26-log' socket: '/u02/run/3308/mysql.sock' port: 3308 Source distribution

正在連接的會話自動中斷

ERROR 2013 (HY000): Lost connection to MySQL server during querymysql>

在配置mysql參數，一定要考慮以下3個因素
1.業務連接預期總數
2.會話初始化內存
3.buffer pool緩沖器大小

下面先用sql查詢一下會話的內存總大小和數據庫buffer pool大小

mysql> select (@@innodb_buffer_pool_size+@@innodb_log_buffer_size+@@key_buffer_size) / 1024 /1024 AS MEMORY_MB;+--------------+| MEMORY_MB |+--------------+| 584.00000000 |+--------------+1 row in set (0.00 sec)mysql> select (@@read_buffer_size+@@read_rnd_buffer_size+@@sort_buffer_size+@@tmp_table_size+@@join_buffer_size+@@binlog_cache_size)/1024/1024 as MB;+--------------+| MB |+--------------+| 160.03125000 |+--------------+1 row in set (0.00 sec)

mysql的buffer pool加上會話內存總大小不超過服務器內存總大小的80%。

假設，服務器內存為32G，mysql數據庫內存設置就不要超過26G，如果buffer pool設置為20G，每個會話內存為160M，則6G能提供6 *1024 /160 =38 個安全連接，超過了，可能造成內存不夠，用swap分區。

總結

以上是生活随笔為你收集整理的mysql服务重启后不见了_一次诡异的Mysql服务不断重启故障排查的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。