1.例項重啟背景
收到監控組同學反饋,連線某一個MongoDB例項的應用耗時異常,並且出現了超時。檢視資料庫監控平臺,發現此例項伺服器的IO異常飆升,而檢視副本集狀態(rs.status()),主從是壞掉的,從節點不可達。
登入從節點,檢視mongodb服務狀態,是stop的。
檢視伺服器的log,發現出現了OOM,Mongodb被關閉了。需要手動重啟。
Jan 17 12:02:48 qqorderdb02 kernel: Out of memory: Kill process 83717 (mongod) score 919 or sacrifice child Jan 17 12:02:48 qqorderdb02 kernel: Killed process 83717 (mongod), UID 1001, total-vm:21256876kB, anon-rss:15529572kB, file-rss:0kB, shmem-rss:0kB Jan 17 12:42:42 qqorderdb02 systemd[1]: mongodbqq.service: main process exited, code=killed, status=9/KILL Jan 17 12:42:42 qqorderdb02 systemd[1]: Unit mongodbqq.service entered failed state. Jan 17 12:42:42 qqorderdb02 systemd[1]: mongodbqq.service failed.
事後分析,主節點的記憶體比從節點的記憶體大,建立索引,主節點正常執行了,而從節點出席那了OOM(12:02),KIll後,服務自啟動也失敗了(12:42)。
2.重啟服務
重啟,檢視mongodblog,我們會看到redo未提交的建立索引的事務
2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'. 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** We suggest setting it to 'never' 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'. 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** We suggest setting it to 'never' 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** WARNING: Running wiredTiger with the --nojournal option in a replica set 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] ** is deprecated and subject to be removed in a future version. 2019-01-17T19:38:11.529+0800 I CONTROL [initandlisten] 2019-01-17T19:38:11.592+0800 I INDEX [initandlisten] found 1 index(es) that wasn't finished before shutdown 2019-01-17T19:38:11.595+0800 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/var/mongodbqq/db/diagnostic.data' 2019-01-17T19:38:11.596+0800 I INDEX [initandlisten] found 1 interrupted index build(s) on qqorderdb.weixinordersn 2019-01-17T19:38:11.596+0800 I INDEX [initandlisten] note: restart the server with --noIndexBuildRetry to skip index rebuilds
但執行一會後,重啟失敗,退出。檢視server log,報錯資訊如下:
Jan 17 19:41:10 qqorderdb02 systemd[1]: mongodbqq.service stop-final-sigterm timed out. Killing. Jan 17 19:41:10 qqorderdb02 systemd[1]: Failed to start mongodbqq_service. Jan 17 19:41:10 qqorderdb02 systemd[1]: Unit mongodbqq.service entered failed state. Jan 17 19:41:10 qqorderdb02 systemd[1]: mongodbqq.service failed.
檢視mongodb的log,最新的資訊如下:
2019-01-17T19:41:00.001+0800 I - [initandlisten] Index Build: 55387600/192576426 28% 2019-01-17T19:41:03.002+0800 I - [initandlisten] Index Build: 57463100/192576426 29% 2019-01-17T19:41:06.002+0800 I - [initandlisten] Index Build: 59385700/192576426 30% 2019-01-17T19:41:09.001+0800 I - [initandlisten] Index Build: 61549000/192576426 31%
通過檢視Server log 和 Mongodb log ,我們可以判斷:啟動時需要重建關閉時未完成的index,但是重建這個大集合(本案例為weixinordersn,5億資料量,102Gsize)的索引耗時較長,超過了啟動服務允許的時間。服務超時後會被killed。
3.解決方案
設定systemd的service超時時間,在mongodb服務中,指明TimeoutSec引數。
TimeoutSec:定義 Systemd 停止當前服務之前等待的秒數。單位是秒,設定為0是不限制.
例如mongodbtest.service的編寫,增加 TimeoutSec=1800
[Unit] Description=mongodbtest After=network.target remote-fs.target nss-lookup.target [Service] User=mongouser Group=mongouser # (open files) LimitNOFILE=64000 Type=forking ExecStart=/data/mongodb/mongobin404/bin/mongod --config /data/mongodb/mongobin404/bin/mongodbtest.conf ExecReload=/bin/kill -s HUP $MAINPID ExecStop=/data/mongodb/mongobin404/bin/mongod --shutdown --config /data/mongodb/mongobin404/bin/mongodbtest.conf PrivateTmp=true TimeoutSec=1800 [Install] WantedBy=multi-user.target
4.效能下降的分析
結合 應用超時 和 資料庫監控的IO飆升的時間關聯,效能下降主要分別是 建立索引 和 主從斷掉導致oplog.rs 插入、查詢、更新變慢導致。
5.參考文獻
1.https://cloudblue.freshdesk.com/support/solutions/articles/44001881778
2.https://www.cnblogs.com/f-society/p/13177614.html
本文版權歸作者所有,未經作者同意不得轉載,謝謝配合!!!