ZabbixでIO系のエラーが頻発していたので確認したところ、kernel: BUG: soft lockup - CPU#x というエラーがでていたので対処した時のメモです。
環境
- ESXi 6.0
- CentOS 7.2
エラーなど
/var/log/messages を確認したところ、以下のエラーが出力されていた。
|
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 |
Jun 29 03:30:38 HOSTNAME kernel: BUG: soft lockup - CPU#1 stuck for 23s! [xfsaild/dm-0:401] Jun 29 03:30:38 HOSTNAME kernel: Modules linked in: ip6t_rpfilter ipt_REJECT ip6t_REJECT xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_security ip6table_raw iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_security iptable_raw ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter vmw_vsock_vmci_transport vsock coretemp crc32_pclmul ghash_clmulni_intel aesni_intel lrw gf128mul glue_helper ablk_helper cryptd pcspkr ppdev sg vmw_balloon parport_pc parport shpchp i2c_piix4 vmw_vmci ip_tables xfs libcrc32c sr_mod cdrom sd_mod crc_t10dif crct10dif_generic ata_generic pata_acpi crct10dif_pclmul crct10dif_common crc32c_intel serio_raw vmwgfx e1000 drm_kms_helper Jun 29 03:30:38 HOSTNAME kernel: ttm mptspi scsi_transport_spi mptscsih drm mptbase ata_piix i2c_core libata floppy dm_mirror dm_region_hash dm_log dm_mod Jun 29 03:30:38 HOSTNAME kernel: CPU: 1 PID: 401 Comm: xfsaild/dm-0 Tainted: G L ------------ 3.10.0-327.el7.x86_64 #1 Jun 29 03:30:38 HOSTNAME kernel: Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 09/30/2014 Jun 29 03:30:38 HOSTNAME kernel: task: ffff880135d96780 ti: ffff880036380000 task.ti: ffff880036380000 Jun 29 03:30:38 HOSTNAME kernel: RIP: 0010:[<ffffffffa00be3be>] [<ffffffffa00be3be>] mpt_put_msg_frame+0x5e/0x80 [mptbase] Jun 29 03:30:38 HOSTNAME kernel: RSP: 0018:ffff880036383b00 EFLAGS: 00000246 Jun 29 03:30:38 HOSTNAME kernel: RAX: ffffc90008780000 RBX: ffff880036383ad0 RCX: 0000000000000018 Jun 29 03:30:38 HOSTNAME kernel: RDX: ffff880135c4f600 RSI: ffff880139157000 RDI: 000000000000000e Jun 29 03:30:38 HOSTNAME kernel: RBP: ffff880036383b10 R08: 0000000000000002 R09: ffff88003640b0d8 Jun 29 03:30:38 HOSTNAME kernel: R10: ffff8800ba2c16c0 R11: ffff8800ba2c16c0 R12: 0000000100000001 Jun 29 03:30:38 HOSTNAME kernel: R13: ffff880097c20300 R14: ffff880036383a74 R15: ffffffff812d06bb Jun 29 03:30:38 HOSTNAME kernel: FS: 0000000000000000(0000) GS:ffff88013fd00000(0000) knlGS:0000000000000000 Jun 29 03:30:38 HOSTNAME kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b Jun 29 03:30:38 HOSTNAME kernel: CR2: 00007fc2c650f000 CR3: 00000000ba1e0000 CR4: 00000000000407e0 Jun 29 03:30:38 HOSTNAME kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 Jun 29 03:30:38 HOSTNAME kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Jun 29 03:30:38 HOSTNAME kernel: Stack: Jun 29 03:30:38 HOSTNAME kernel: ffff880139157d30 000000000000003c ffff880036383bb8 ffffffffa008b729 Jun 29 03:30:38 HOSTNAME kernel: ffff880139157008 0400000036383b78 0000000000000018 ffff8800ba2c16c0 Jun 29 03:30:38 HOSTNAME kernel: 0000000000000060 ffff880139157188 0000006000000018 ffff880036603130 Jun 29 03:30:38 HOSTNAME kernel: Call Trace: Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa008b729>] mptscsih_qcmd+0x249/0x820 [mptscsih] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa00962b0>] mptspi_qcmd+0x50/0xe0 [mptspi] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff81417b1a>] scsi_dispatch_cmd+0xaa/0x230 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff81420aa1>] scsi_request_fn+0x501/0x770 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff812c73e3>] __blk_run_queue+0x33/0x40 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff812c749a>] queue_unplugged+0x2a/0xa0 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff812cbd18>] blk_flush_plug_list+0x1d8/0x230 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff812cc124>] blk_finish_plug+0x14/0x40 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa0258a79>] __xfs_buf_delwri_submit+0x1e9/0x250 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa025967f>] ? xfs_buf_delwri_submit_nowait+0x2f/0x50 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa0284470>] ? xfs_trans_ail_cursor_first+0x90/0x90 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa025967f>] xfs_buf_delwri_submit_nowait+0x2f/0x50 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa02846b0>] xfsaild+0x240/0x5e0 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffffa0284470>] ? xfs_trans_ail_cursor_first+0x90/0x90 [xfs] Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff810a5aef>] kthread+0xcf/0xe0 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff810a5a20>] ? kthread_create_on_node+0x140/0x140 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff81645858>] ret_from_fork+0x58/0x90 Jun 29 03:30:38 HOSTNAME kernel: [<ffffffff810a5a20>] ? kthread_create_on_node+0x140/0x140 Jun 29 03:30:38 HOSTNAME kernel: Code: 8b 96 68 01 00 00 0f b7 c8 44 03 a6 b0 01 00 00 44 8b 04 8a 45 09 c4 f686 e0 00 00 00 04 75 10 48 8b 83 e8 00 00 00 44 89 60 40 <5b> 41 5c 5d c3 48 8d 76 08 0f b7 c8 44 89 e2 48 c7 c7 78 c3 0c |
発生が夜中だったので特に何も影響はなかったが、Zabbixで監視状態をみるとIO系のエラーが頻発していた。ただ、数分で収まり元に戻っていた。
調べてみると、VMwareのKB「SMP 対応の仮想マシンで実行中の Linux カーネルからソフト ロックアップ メッセージが出力される (2094326)」に以下の記載があった。
Linux カーネルがソフト ロックアップ用のウォッチドッグ スレッドを用意しており、このウォッチドッグ スレッドが 10 秒間以上スケジュールされない場合は、ソフト ロックアップ メッセージが出力されます。
対応策として、以下のように記載があるが気持ち悪いので対処したい。。。
ソフト ロックアップ メッセージが出力されても、カーネル パニックが発生したわけではないため、無視しても問題ありません。
上記VMのページにはソフトロックアップのしきい値を変更する方法が紹介されているが、これって根本解決になってなくないか？と思い探してみると「BUG: soft lockup - CPU# で止まってしまう」で有識者と思われる方が解説していた。
VM環境でオーバーコミットしているような場合だと、VMが実CPUを常にとれているわけではない（ほかのVMが忙しい場合には当然暇なVMにはリソースは割り当てられない。）リソースプールで制御している場合は別だが。
確かに、メッセージが出ていた環境はまぁまぁなオーバーコミット具合いだった。経験上、メモリはある程度のオーバーヘッドでパフォーマンスの違いが見えやすいからオーバーコミットに対して少し神経質になるけど、CPUはすべてのVMが忙しく動いているわけではない（ことが多い）のでそこまで厳しく計算をしない（ことが多い、わたしは）。
対処
参考にさせてもらって、というかそのままだが、以下のように設定変更後にVMの再起動を行いました。
|
1 2 3 4 |
# vi /boot/config-3.10.0-327.el7.x86_64 CONFIG_LOCKUP_DETECTOR=y ↓ CONFIG_LOCKUP_DETECTOR=n |
|
1 |
# shutdown -r now |
以上です。
↓↓↓ 持っていると便利な一冊。
