pod cause coreos crashed with 'soft lockup - CPU stuck' error

[kun...@shenzhou-ucar.com]

Recently I've got several servers crashed at almost the same time.

The environment:  coreos 1298.5.0 , hyperkube 1.6.4, baremetal.

The pod runs 4 instances on 4 servers, recently the 4 servers crashed one by one. One thing about the pod is that it's memory increased quickly, linearly increased upto 27GB before crash. except one that didn't got pstore log, the other three servers all had pstore log , that had the 'cpu stuck'  keyword, and the process  that running at the time being was docker-runc.

Can somebody give some hints ?  How can a malfunction pod crash a server ? how can I avoid this?

the logs excerpt from /sys/fs/pstore:

<6>[785261.150014] IPv6: ADDRCONF(NETDEV_UP): cali33fe5b5c4cf: link is not ready
<6>[785261.201822] eth0: renamed from tmp33fe5b5c4cf
<6>[785261.249059] IPv6: ADDRCONF(NETDEV_CHANGE): cali33fe5b5c4cf: link becomes ready
<4>[785262.496497] SELinux: mount invalid.  Same superblock, different security settings for (dev mqueue, type mqueue)
<0>[785554.079546] NMI watchdog: BUG: soft lockup - CPU#20 stuck for 23s! [docker-runc:10506]
<4>[785554.088590] Modules linked in: nfnetlink_queue nfnetlink_log binfmt_misc nfsd auth_rpcgss nfs_acl lockd grace sunrpc veth fus
e xt_statistic xt_physdev xt_nat xt_recent ipt_REJECT nf_reject_ipv4 xt_set ip_set xt_mac xt_mark ip6t_rpfilter xt_comment nf_conntr
ack_netlink ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_raw nfnetlink ip6table_filter ip6_tables ipt_MASQUERA
DE nf_nat_masquerade_ipv4 xfrm_user xfrm_algo iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype iptable_filter xt
_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay bonding nls_ascii nls_cp437 vfat fat coretemp sb_edac edac_core s
es enclosure x86_pkg_temp_thermal ipmi_ssif i2c_core kvm_intel scsi_transport_sas ipmi_devintf kvm ipmi_si evdev irqbypass dcdbas ip
mi_msghandler mei_me mei
<4>[785554.174553]  button sch_fq_codel ip_tables ext4 crc16 jbd2 fscrypto mbcache mlx4_en sd_mod crc32c_intel ehci_pci aesni_intel 
ahci aes_x86_64 glue_helper tg3 libahci lrw ehci_hcd hwmon gf128mul megaraid_sas libata ablk_helper ptp cryptd mlx4_core usbcore scs
i_mod pps_core usb_common libphy dm_mirror dm_region_hash dm_log dm_mod autofs4
<4>[785554.210952] CPU: 20 PID: 10506 Comm: docker-runc Not tainted 4.9.9-coreos-r1 #1
<4>[785554.219805] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.1.7 06/16/2016
<4>[785554.228913] task: ffffa14c93c2bb80 task.stack: ffffb7d6d9d84000
<4>[785554.235929] RIP: 0010:[<ffffffff984a184d>]  [<ffffffff984a184d>] sock_from_file+0xd/0x30
<4>[785554.245803] RSP: 0018:ffffb7d6d9d87af0  EFLAGS: 00000283
<4>[785554.252233] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
<4>[785554.260844] RDX: 0000000000017483 RSI: ffffb7d6d9d87afc RDI: ffffa1234ddb8f00
<4>[785554.269474] RBP: ffffb7d6d9d87b18 R08: 0000000000000001 R09: ffffb7d6d9d87c60
<4>[785554.278087] R10: ffffa17cf4039a00 R11: 0000000000000001 R12: ffffffff984ea520
<4>[785554.286719] R13: 0000000000000000 R14: ffffa14499dd0e40 R15: ffffa169511d7cc0
<4>[785554.295316] FS:  00007f6eb1643700(0000) GS:ffffa14d3fa80000(0000) knlGS:0000000000000000
<4>[785554.310674] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[785554.317505] CR2: 000000c8200d0580 CR3: 0000003c11c77000 CR4: 00000000003406e0
<4>[785554.326160] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[785554.334768] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[785554.343445] Stack:
<4>[785554.346135]  ffffffff984ea54e ffffffa89822539e 000000003673549d 0000000000017483
<4>[785554.355544]  ffffffff984ea520 ffffb7d6d9d87b50 ffffffff982253a6 ffffa1704a23a508
<4>[785554.364899]  ffffa1704a239dc0 0000000000000000 ffffb7d6d9d87c50 ffffa17cf4039a00
<4>[785554.374149] Call Trace:
<4>[785554.377309]  [<ffffffff984ea54e>] ? update_classid_sock+0x2e/0xb0
<4>[785554.384543]  [<ffffffff984ea520>] ? read_classid+0x20/0x20
<4>[785554.391082]  [<ffffffff982253a6>] iterate_fd+0x56/0x80
<4>[785554.397273]  [<ffffffff984ea668>] update_classid+0x58/0xa0
<4>[785554.403830]  [<ffffffff984ea714>] cgrp_attach+0x34/0x50
<4>[785554.410063]  [<ffffffff9810dbf6>] cgroup_taskset_migrate+0x186/0x320
<4>[785554.417606]  [<ffffffff9810de48>] cgroup_migrate+0xb8/0xe0
<4>[785554.424129]  [<ffffffff9810df6d>] cgroup_attach_task+0xfd/0x1a0
<4>[785554.431170]  [<ffffffff9810e2f3>] __cgroup_procs_write+0x203/0x330
<4>[785554.438459]  [<ffffffff9810e454>] cgroup_procs_write+0x14/0x20
<4>[785554.445400]  [<ffffffff98109224>] cgroup_file_write+0x44/0x100
<4>[785554.452342]  [<ffffffff98286187>] kernfs_fop_write+0x117/0x190
<4>[785554.459270]  [<ffffffff98205157>] __vfs_write+0x37/0x140
<4>[785554.465680]  [<ffffffff982b3288>] ? selinux_file_permission+0xe8/0x120
<4>[785554.473367]  [<ffffffff982a81ab>] ? security_file_permission+0x3b/0xc0
<4>[785554.481074]  [<ffffffff98205e48>] vfs_write+0xb8/0x1a0
<4>[785554.487225]  [<ffffffff980033de>] ? syscall_trace_enter+0x1ce/0x2c0
<4>[785554.494631]  [<ffffffff982072a5>] SyS_write+0x55/0xc0
<4>[785554.500668]  [<ffffffff98003b3a>] do_syscall_64+0x5a/0x160
<4>[785554.507192]  [<ffffffff985cddeb>] entry_SYSCALL64_slow_path+0x25/0x25
<4>[785554.514783] Code: ea 83 e2 01 eb d2 90 90 90 90 90 90 90 90 0f 1f 44 00 00 55 b8 f5 ff ff ff 48 89 e5 5d c3 0f 1f 44 00 00 48
 81 7f 28 c0 71 68 98 <55> 48 89 e5 75 09 48 8b 87 d0 00 00 00 5d c3 31 c0 c7 06 a8 ff 
<0>[785554.542891] Kernel panic - not syncing: softlockup: hung tasks
<4>[785554.549912] CPU: 20 PID: 10506 Comm: docker-runc Tainted: G             L  4.9.9-coreos-r1 #1
<4>[785554.560241] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.1.7 06/16/2016
<4>[785554.569349]  ffffa14d3fa83e58 ffffffff9831a933 0000000000000000 ffffffff987beefd
<4>[785554.578665]  ffffa14d3fa83ee0 ffffffff9817e035 0000000000000008 ffffa14d3fa83ef0
<4>[785554.587892]  ffffa14d3fa83e88 000000003673549d 0000000000000000 0000000000000000
<4>[785554.597193] Call Trace:
<4>[785554.600404]  <IRQ> 
<4>[785554.602756]  [<ffffffff9831a933>] dump_stack+0x63/0x90
<4>[785554.609270]  [<ffffffff9817e035>] panic+0xe8/0x236
<4>[785554.615052]  [<ffffffff98128255>] watchdog_timer_fn+0x1e5/0x1f0
<4>[785554.622103]  [<ffffffff98128070>] ? watchdog+0x40/0x40
<4>[785554.628277]  [<ffffffff980e6513>] __hrtimer_run_queues+0xf3/0x280
<4>[785554.635495]  [<ffffffff980e69e8>] hrtimer_interrupt+0xa8/0x1a0
<4>[785554.642428]  [<ffffffff984ea520>] ? read_classid+0x20/0x20
<4>[785554.649008]  [<ffffffff98053008>] local_apic_timer_interrupt+0x38/0x60
<4>[785554.656839]  [<ffffffff985d063d>] smp_apic_timer_interrupt+0x3d/0x50
<4>[785554.664374]  [<ffffffff985cf952>] apic_timer_interrupt+0x82/0x90
<4>[785554.671493]  <EOI> 
<4>[785554.673812]  [<ffffffff984ea520>] ? read_classid+0x20/0x20
<4>[785554.680665]  [<ffffffff984a184d>] ? sock_from_file+0xd/0x30
<4>[785554.687307]  [<ffffffff984ea54e>] ? update_classid_sock+0x2e/0xb0
<4>[785554.694525]  [<ffffffff984ea520>] ? read_classid+0x20/0x20
<4>[785554.701066]  [<ffffffff982253a6>] iterate_fd+0x56/0x80
<4>[785554.707254]  [<ffffffff984ea668>] update_classid+0x58/0xa0
<4>[785554.713840]  [<ffffffff984ea714>] cgrp_attach+0x34/0x50
<4>[785554.720072]  [<ffffffff9810dbf6>] cgroup_taskset_migrate+0x186/0x320
<4>[785554.727563]  [<ffffffff9810de48>] cgroup_migrate+0xb8/0xe0
<4>[785554.734134]  [<ffffffff9810df6d>] cgroup_attach_task+0xfd/0x1a0
<4>[785554.741156]  [<ffffffff9810e2f3>] __cgroup_procs_write+0x203/0x330
<4>[785554.748530]  [<ffffffff9810e454>] cgroup_procs_write+0x14/0x20
<4>[785554.755499]  [<ffffffff98109224>] cgroup_file_write+0x44/0x100
<4>[785554.762428]  [<ffffffff98286187>] kernfs_fop_write+0x117/0x190
<4>[785554.769383]  [<ffffffff98205157>] __vfs_write+0x37/0x140
<4>[785554.775722]  [<ffffffff982b3288>] ? selinux_file_permission+0xe8/0x120
<4>[785554.783440]  [<ffffffff982a81ab>] ? security_file_permission+0x3b/0xc0
<4>[785554.791183]  [<ffffffff98205e48>] vfs_write+0xb8/0x1a0
<4>[785554.797364]  [<ffffffff980033de>] ? syscall_trace_enter+0x1ce/0x2c0
<4>[785554.804762]  [<ffffffff982072a5>] SyS_write+0x55/0xc0
<4>[785554.810812]  [<ffffffff98003b3a>] do_syscall_64+0x5a/0x160
<4>[785554.817366]  [<ffffffff985cddeb>] entry_SYSCALL64_slow_path+0x25/0x25
<0>[785555.015692] Kernel Offset: 0x17000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

thanks.

likun

[Euan Kemp]

On 06/11/2017 02:54 AM, kun...@shenzhou-ucar.com wrote:
> Recently I've got several servers crashed at almost the same time.
>
> The environment: coreos 1298.5.0 , hyperkube 1.6.4, baremetal.
>
> The pod runs 4 instances on 4 servers, recently the 4 servers crashed
> one by one. One thing about the pod is that it's memory increased
> quickly, linearly increased upto 27GB before crash. except one that
> didn't got pstore log, the other three servers all had pstore log , that
> had the 'cpu stuck' keyword, and the process that running at the time
> being was docker-runc.
> Can somebody give some hints

> How can a malfunction pod crash a server?

When a pod can crash the server, that usually means a kernel bug, though
it could also be a hardware issue.

> how can I avoid this?

In this case, you're running an old version of Container Linux with an
older kernel.

Your stack trace also shows that it's taking an excessive amount of time
to do a cgroup_attach call (somewhere under iterate_fd).
That sounds suspiciously similar to the pathological case described in
this patch: https://patchwork.kernel.org/patch/9649293/

That patch made it into the 4.9 kernel in 4.9.19, and it happens the
latest Container Linux stable version has the 4.9.24 kernel.

Letting Container Linux update very well might fix this issue.
If it doesn't, then please do re-report it.


Best,
Euan

[kun...@shenzhou-ucar.com]

Ok, I'll give newest coreos a try. But from where I can tell that the cgroup_attach call took excessive amount of time?

likun