[vserver] Soft Lockup Problem and load race with 2.6.33.2 and 2.3.0.26.30.4

From: Cryptronic <mail_at_cryptronic.de>
Date: Sat 08 May 2010 - 18:15:23 BST
Message-ID: <4BE59C2B.2020508@cryptronic.de>

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi list,

I experienced some days ago a strange problem:

After a load average from 7315.37, 2565.58, 922.92 i reseted the
system because nothing works anymore.

The following notes i get out of kern.log:

Apr 26 19:30:50 s4311 kernel: [474991.174201] BUG: soft lockup -
CPU#10 stuck for 61s! [htop:14708]
Apr 26 19:30:50 s4311 kernel: [474991.180387] Modules linked in:
tcp_diag inet_diag iptable_nat tun act_mirred sch_ingress cls_u32
sch_htb ifb nfs lockd nfs_acl auth_rpcgss sunrpc xt_tcpudp xt_state
ipt_REJECT ipt_LOG xt_limit iptable_filter xt_DSCP xt_recent
nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack_irc nf_conntrack_ipv4
nf_conntrack nf_defrag_ipv4 ip_tables x_tables loop evdev dcdbas
tpm_tis tpm tpm_bios serio_raw psmouse pcspkr processor button
dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sg sr_mod cdrom
ata_generic ata_piix libata ide_pci_generic ide_core ehci_hcd uhci_hcd
usbcore nls_base sd_mod crc_t10dif ses enclosure bnx2 thermal fan
thermal_sys [last unloaded: scsi_wait_scan]
Apr 26 19:30:50 s4311 kernel: [474991.180441] CPU 10
Apr 26 19:30:50 s4311 kernel: [474991.180445] Pid: 14708, comm: htop
Tainted: G W 2.6.33.2-vs2.3.0.36.30.4 #5 PowerEdge R710
Apr 26 19:30:50 s4311 kernel: [474991.180449] RIP:
0010:[<ffffffff81354bbb>] [<ffffffff81354bbb>] _raw_spin_lock+0xa/0x15
Apr 26 19:30:50 s4311 kernel: [474991.180458] RSP:
0018:ffff8806d7843c70 EFLAGS: 00000202
Apr 26 19:30:50 s4311 kernel: [474991.180461] RAX: 0000000000007a7a
RBX: ffff8811c64b9720 RCX: 0000000000000000
Apr 26 19:30:50 s4311 kernel: [474991.180464] RDX: 000000003b29d295
RSI: 000000000007432f RDI: ffff8811c64b9af4
Apr 26 19:30:50 s4311 kernel: [474991.180467] RBP: ffffffff8100340e
R08: 0000000000000000 R09: ffffffff8140b554
Apr 26 19:30:50 s4311 kernel: [474991.180469] R10: 0000000000000002
R11: ffff880856b41660 R12: ffffffff811a9ae7
Apr 26 19:30:50 s4311 kernel: [474991.180472] R13: ffffffff8100340e
R14: ffff8806d7843be8 R15: 00000000344c04ff
Apr 26 19:30:50 s4311 kernel: [474991.180476] FS:
00007f188d47d6e0(0000) GS:ffff88094fca0000(0000) knlGS:0000000000000000
Apr 26 19:30:50 s4311 kernel: [474991.180479] CS: 0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Apr 26 19:30:50 s4311 kernel: [474991.180481] CR2: 00007f188d482000
CR3: 00000007e965e000 CR4: 00000000000006e0
Apr 26 19:30:50 s4311 kernel: [474991.180484] DR0: 0000000000000000
DR1: 0000000000000000 DR2: 0000000000000000
Apr 26 19:30:50 s4311 kernel: [474991.180487] DR3: 0000000000000000
DR6: 00000000ffff0ff0 DR7: 0000000000000400
Apr 26 19:30:50 s4311 kernel: [474991.180490] Process htop (pid:
14708, threadinfo ffff8806d7842000, task ffff880752041620)
Apr 26 19:30:50 s4311 kernel: [474991.180492] Stack:
Apr 26 19:30:50 s4311 kernel: [474991.182600] ffffffff810b3a89
ffff880752041620 ffff880752041620 0000000000000018
Apr 26 19:30:50 s4311 kernel: [474991.182603] <0> 00001b6e00000000
000000000007432f 000000003b29d295 0000000000000000
Apr 26 19:30:50 s4311 kernel: [474991.182607] <0> 0000000000000001
0000000000000002 0000000000000001 00007f188d482000
Apr 26 19:30:50 s4311 kernel: [474991.182612] Call Trace:
Apr 26 19:30:50 s4311 kernel: [474991.185159] [<ffffffff810b3a89>] ?
__out_of_memory+0xa1/0x1db
Apr 26 19:30:50 s4311 kernel: [474991.185163] [<ffffffff810b3d99>] ?
pagefault_out_of_memory+0x54/0x7f
Apr 26 19:30:50 s4311 kernel: [474991.185169] [<ffffffff81024567>] ?
mm_fault_error+0x3b/0x11c
Apr 26 19:30:50 s4311 kernel: [474991.185173] [<ffffffff810248a7>] ?
do_page_fault+0x25f/0x27b
Apr 26 19:30:50 s4311 kernel: [474991.185178] [<ffffffff81355205>] ?
page_fault+0x25/0x30
Apr 26 19:30:50 s4311 kernel: [474991.185184] [<ffffffff811e487d>] ?
copy_user_generic_string+0x2d/0x40
Apr 26 19:30:50 s4311 kernel: [474991.185190] [<ffffffff8110140d>] ?
seq_read+0x30f/0x38f
Apr 26 19:30:50 s4311 kernel: [474991.185196] [<ffffffff810ccc77>] ?
get_unmapped_area+0xd7/0x139
Apr 26 19:30:50 s4311 kernel: [474991.185202] [<ffffffff8112cac4>] ?
proc_reg_read+0x76/0x90
Apr 26 19:30:50 s4311 kernel: [474991.185207] [<ffffffff810e986b>] ?
vfs_read+0xa6/0xff
Apr 26 19:30:50 s4311 kernel: [474991.185211] [<ffffffff810e9980>] ?
sys_read+0x45/0x6e
Apr 26 19:30:50 s4311 kernel: [474991.185215] [<ffffffff81002a42>] ?
system_call_fastpath+0x16/0x1b
Apr 26 19:30:50 s4311 kernel: [474991.185217] Code: 0f b7 07 38 e0 8d
90 00 01 00 00 75 05 f0 66 0f b1 17 0f 94 c2 0f b6 c2 85 c0 0f 95 c0
0f b6 c0 c3 b8 00 01 00 00 f0 66 0f c1 07 <38> e0 74 06 f3 90 8a 07 eb
f6 c3 48 83 ec 08 9c 58 0f 1f 44 00
Apr 26 19:30:50 s4311 kernel: [474991.204992] Call Trace:
Apr 26 19:30:50 s4311 kernel: [474991.204995] [<ffffffff810b3a89>] ?
__out_of_memory+0xa1/0x1db
Apr 26 19:30:50 s4311 kernel: [474991.204999] [<ffffffff810b3d99>] ?
pagefault_out_of_memory+0x54/0x7f
Apr 26 19:30:50 s4311 kernel: [474991.205002] [<ffffffff81024567>] ?
mm_fault_error+0x3b/0x11c
Apr 26 19:30:50 s4311 kernel: [474991.205006] [<ffffffff810248a7>] ?
do_page_fault+0x25f/0x27b
Apr 26 19:30:50 s4311 kernel: [474991.205009] [<ffffffff81355205>] ?
page_fault+0x25/0x30
Apr 26 19:30:50 s4311 kernel: [474991.205013] [<ffffffff811e487d>] ?
copy_user_generic_string+0x2d/0x40
Apr 26 19:30:50 s4311 kernel: [474991.205016] [<ffffffff8110140d>] ?
seq_read+0x30f/0x38f
Apr 26 19:30:50 s4311 kernel: [474991.205019] [<ffffffff810ccc77>] ?
get_unmapped_area+0xd7/0x139
Apr 26 19:30:50 s4311 kernel: [474991.205023] [<ffffffff8112cac4>] ?
proc_reg_read+0x76/0x90
Apr 26 19:30:50 s4311 kernel: [474991.205026] [<ffffffff810e986b>] ?
vfs_read+0xa6/0xff
Apr 26 19:30:50 s4311 kernel: [474991.205029] [<ffffffff810e9980>] ?
sys_read+0x45/0x6e
Apr 26 19:30:50 s4311 kernel: [474991.205033] [<ffffffff81002a42>] ?
system_call_fastpath+0x16/0x1b
Apr 26 19:30:50 s4311 kernel: [475056.672891] BUG: soft lockup -
CPU#10 stuck for 61s! [htop:14708]
Apr 26 19:30:50 s4311 kernel: [475056.679078] Modules linked in:
tcp_diag inet_diag iptable_nat tun act_mirred sch_ingress cls_u32
sch_htb ifb nfs lockd nfs_acl auth_rpcgss sunrpc xt_tcpudp xt_state
ipt_REJECT ipt_LOG xt_limit iptable_filter xt_DSCP xt_recent
nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack_irc nf_conntrack_ipv4
nf_conntrack nf_defrag_ipv4 ip_tables x_tables loop evdev dcdbas
tpm_tis tpm tpm_bios serio_raw psmouse pcspkr processor button
dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sg sr_mod cdrom
ata_generic ata_piix libata ide_pci_generic ide_core ehci_hcd uhci_hcd
usbcore nls_base sd_mod crc_t10dif ses enclosure bnx2 thermal fan
thermal_sys [last unloaded: scsi_wait_scan]
Apr 26 19:30:50 s4311 kernel: [475056.679131] CPU 10
Apr 26 19:30:50 s4311 kernel: [475056.679135] Pid: 14708, comm: htop
Tainted: G W 2.6.33.2-vs2.3.0.36.30.4 #5 PowerEdge R710
Apr 26 19:30:50 s4311 kernel: [475056.679139] RIP:
0010:[<ffffffff81354bbb>] [<ffffffff81354bbb>] _raw_spin_lock+0xa/0x15
Apr 26 19:30:50 s4311 kernel: [475056.679148] RSP:
0018:ffff8806d7843c70 EFLAGS: 00000286
Apr 26 19:30:50 s4311 kernel: [475056.679151] RAX: 000000000000fcf9
RBX: ffff881121b34aa0 RCX: 0000000000000000
Apr 26 19:30:50 s4311 kernel: [475056.679154] RDX: 0000000024bed554
RSI: 0000000000074371 RDI: ffff881121b34e74
Apr 26 19:30:50 s4311 kernel: [475056.679157] RBP: ffffffff8100340e
R08: 0000000000000000 R09: ffffffff8140b554
Apr 26 19:30:50 s4311 kernel: [475056.679159] R10: 0000000000000002
R11: ffff880856b41660 R12: ffffffff811a9ae7
Apr 26 19:30:50 s4311 kernel: [475056.679162] R13: ffffffff81354bbf
R14: ffffffffffffff10 R15: 00000000344c04ff
Apr 26 19:30:50 s4311 kernel: [475056.679166] FS:
00007f188d47d6e0(0000) GS:ffff88094fca0000(0000) knlGS:0000000000000000
Apr 26 19:30:50 s4311 kernel: [475056.679169] CS: 0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Apr 26 19:30:50 s4311 kernel: [475056.679171] CR2: 00007f188d482000
CR3: 00000007e965e000 CR4: 00000000000006e0
Apr 26 19:30:50 s4311 kernel: [475056.679174] DR0: 0000000000000000
DR1: 0000000000000000 DR2: 0000000000000000
Apr 26 19:30:50 s4311 kernel: [475056.679177] DR3: 0000000000000000
DR6: 00000000ffff0ff0 DR7: 0000000000000400
Apr 26 19:30:50 s4311 kernel: [475056.679180] Process htop (pid:
14708, threadinfo ffff8806d7842000, task ffff880752041620)
Apr 26 19:30:50 s4311 kernel: [475056.679182] Stack:
Apr 26 19:30:50 s4311 kernel: [475056.681289] ffffffff810b3a89
ffff880752041620 ffff880752041620 00000000d7842000
Apr 26 19:30:50 s4311 kernel: [475056.681293] <0> 00001b6e00000000
0000000000074371 0000000024bed554 0000000000000000
Apr 26 19:30:50 s4311 kernel: [475056.681297] <0> 0000000000000001
0000000000000002 0000000000000001 00007f188d482000
Apr 26 19:30:50 s4311 kernel: [475056.681301] Call Trace:
Apr 26 19:30:50 s4311 kernel: [475056.683847] [<ffffffff810b3a89>] ?
__out_of_memory+0xa1/0x1db
Apr 26 19:30:50 s4311 kernel: [475056.683851] [<ffffffff810b3d99>] ?
pagefault_out_of_memory+0x54/0x7f
Apr 26 19:30:50 s4311 kernel: [475056.683857] [<ffffffff81024567>] ?
mm_fault_error+0x3b/0x11c
Apr 26 19:30:50 s4311 kernel: [475056.683861] [<ffffffff810248a7>] ?
do_page_fault+0x25f/0x27b
Apr 26 19:30:50 s4311 kernel: [475056.683865] [<ffffffff81355205>] ?
page_fault+0x25/0x30
Apr 26 19:30:50 s4311 kernel: [475056.683872] [<ffffffff811e487d>] ?
copy_user_generic_string+0x2d/0x40
Apr 26 19:30:50 s4311 kernel: [475056.683878] [<ffffffff8110140d>] ?
seq_read+0x30f/0x38f
Apr 26 19:30:50 s4311 kernel: [475056.683883] [<ffffffff810ccc77>] ?
get_unmapped_area+0xd7/0x139
Apr 26 19:30:50 s4311 kernel: [475056.683890] [<ffffffff8112cac4>] ?
proc_reg_read+0x76/0x90
Apr 26 19:30:50 s4311 kernel: [475056.683895] [<ffffffff810e986b>] ?
vfs_read+0xa6/0xff
Apr 26 19:30:50 s4311 kernel: [475056.683898] [<ffffffff810e9980>] ?
sys_read+0x45/0x6e
Apr 26 19:30:50 s4311 kernel: [475056.683903] [<ffffffff81002a42>] ?
system_call_fastpath+0x16/0x1b
Apr 26 19:30:50 s4311 kernel: [475056.683905] Code: 0f b7 07 38 e0 8d
90 00 01 00 00 75 05 f0 66 0f b1 17 0f 94 c2 0f b6 c2 85 c0 0f 95 c0
0f b6 c0 c3 b8 00 01 00 00 f0 66 0f c1 07 <38> e0 74 06 f3 90 8a 07 eb
f6 c3 48 83 ec 08 9c 58 0f 1f 44 00
Apr 26 19:30:50 s4311 kernel: [475056.708661] Call Trace:
Apr 26 19:30:50 s4311 kernel: [475056.708664] [<ffffffff810b3a89>] ?
__out_of_memory+0xa1/0x1db
Apr 26 19:30:50 s4311 kernel: [475056.708667] [<ffffffff810b3d99>] ?
pagefault_out_of_memory+0x54/0x7f
Apr 26 19:30:50 s4311 kernel: [475056.708671] [<ffffffff81024567>] ?
mm_fault_error+0x3b/0x11c
Apr 26 19:30:50 s4311 kernel: [475056.708674] [<ffffffff810248a7>] ?
do_page_fault+0x25f/0x27b
Apr 26 19:30:50 s4311 kernel: [475056.708678] [<ffffffff81355205>] ?
page_fault+0x25/0x30
Apr 26 19:30:50 s4311 kernel: [475056.708681] [<ffffffff811e487d>] ?
copy_user_generic_string+0x2d/0x40
Apr 26 19:30:50 s4311 kernel: [475056.708685] [<ffffffff8110140d>] ?
seq_read+0x30f/0x38f
Apr 26 19:30:50 s4311 kernel: [475056.708688] [<ffffffff810ccc77>] ?
get_unmapped_area+0xd7/0x139
Apr 26 19:30:50 s4311 kernel: [475056.708692] [<ffffffff8112cac4>] ?
proc_reg_read+0x76/0x90
Apr 26 19:30:50 s4311 kernel: [475056.708695] [<ffffffff810e986b>] ?
vfs_read+0xa6/0xff
Apr 26 19:30:50 s4311 kernel: [475056.708698] [<ffffffff810e9980>] ?
sys_read+0x45/0x6e
Apr 26 19:30:50 s4311 kernel: [475056.708701] [<ffffffff81002a42>] ?
system_call_fastpath+0x16/0x1b
Apr 26 19:34:33 s4311 kernel: [475122.168565] BUG: soft lockup -
CPU#10 stuck for 61s! [htop:14708]
Apr 26 19:34:33 s4311 kernel: [475122.174750] Modules linked in:
tcp_diag inet_diag iptable_nat tun act_mirred sch_ingress cls_u32
sch_htb ifb nfs lockd nfs_acl auth_rpcgss sunrpc xt_tcpudp xt_state
ipt_REJECT ipt_LOG xt_limit iptable_filter xt_DSCP xt_recent
nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack_irc nf_conntrack_ipv4
nf_conntrack nf_defrag_ipv4 ip_tables x_tables loop evdev dcdbas
tpm_tis tpm tpm_bios serio_raw psmouse pcspkr processor button
dm_mirror dm_region_hash dm_log dm_snapshot dm_mod sg sr_mod cdrom
ata_generic ata_piix libata ide_pci_generic ide_core ehci_hcd uhci_hcd
usbcore nls_base sd_mod crc_t10dif ses enclosure bnx2 thermal fan
thermal_sys [last unloaded: scsi_wait_scan]
Apr 26 19:34:33 s4311 kernel: [475122.174801] CPU 10
Apr 26 19:34:33 s4311 kernel: [475122.174805] Pid: 14708, comm: htop
Tainted: G W 2.6.33.2-vs2.3.0.36.30.4 #5 PowerEdge R710
Apr 26 19:34:33 s4311 kernel: [475122.174808] RIP:
0010:[<ffffffff81354bbb>] [<ffffffff81354bbb>] _raw_spin_lock+0xa/0x15
Apr 26 19:34:33 s4311 kernel: [475122.174817] RSP:
0018:ffff8806d7843c70 EFLAGS: 00000282
Apr 26 19:34:33 s4311 kernel: [475122.174820] RAX: 000000000000bfbf
RBX: ffff880853e0e300 RCX: 0000000000000000
Apr 26 19:34:33 s4311 kernel: [475122.174822] RDX: 000000000fc4531d
RSI: 00000000000743b3 RDI: ffff880853e0e6d4
Apr 26 19:34:33 s4311 kernel: [475122.174825] RBP: ffffffff8100340e
R08: 0000000000000000 R09: ffffffff8140b554
Apr 26 19:34:33 s4311 kernel: [475122.174827] R10: 0000000000000002
R11: ffff880856b41660 R12: ffffffff811a9ae7
Apr 26 19:34:33 s4311 kernel: [475122.174830] R13: ffffffff81354bc3
R14: ffffffffffffff10 R15: 00000000344c04ff
Apr 26 19:34:33 s4311 kernel: [475122.174833] FS:
00007f188d47d6e0(0000) GS:ffff88094fca0000(0000) knlGS:0000000000000000
Apr 26 19:34:33 s4311 kernel: [475122.174836] CS: 0010 DS: 0000 ES:
0000 CR0: 0000000080050033
Apr 26 19:34:33 s4311 kernel: [475122.174838] CR2: 00007f188d482000
CR3: 00000007e965e000 CR4: 00000000000006e0
Apr 26 19:34:33 s4311 kernel: [475122.174840] DR0: 0000000000000000
DR1: 0000000000000000 DR2: 0000000000000000
Apr 26 19:34:33 s4311 kernel: [475122.174843] DR3: 0000000000000000
DR6: 00000000ffff0ff0 DR7: 0000000000000400
Apr 26 19:34:33 s4311 kernel: [475122.174846] Process htop (pid:
14708, threadinfo ffff8806d7842000, task ffff880752041620)
Apr 26 19:34:33 s4311 kernel: [475122.174848] Stack:

Is this a vserver bug?

# vserver-info
Versions:
                   Kernel: 2.6.33.2-vs2.3.0.36.30.4
                   VS-API: 0x00020305
             util-vserver: 0.30.216-pre2883; Apr 4 2010, 19:57:41

Features:
                       CC: gcc, gcc (Debian 4.3.2-1.1) 4.3.2
                      CXX: g++, g++ (Debian 4.3.2-1.1) 4.3.2
                 CPPFLAGS: ''
                   CFLAGS: '-Wall -g -O2 -std=c99 -Wall -pedantic -W
- -funit-at-a-time'
                 CXXFLAGS: '-g -O2 -ansi -Wall -pedantic -W
- -fmessage-length=0 -funit-at-a-time'
               build/host: x86_64-pc-linux-gnu/x86_64-pc-linux-gnu
             Use dietlibc: yes
       Build C++ programs: yes
       Build C99 programs: yes
           Available APIs: v13,net,v21,v22,v23,netv2
            ext2fs Source: e2fsprogs
    syscall(2) invocation: alternative
      vserver(2) syscall#: 236/glibc
               crypto api: beecrypt
          python bindings: no
   use library versioning: yes

Paths:
                   prefix: /usr
        sysconf-Directory: /etc
            cfg-Directory: /etc/vservers
         initrd-Directory: $(sysconfdir)/init.d
       pkgstate-Directory: /var/run/vservers
          vserver-Rootdir: /var/lib/vservers

I'm using the util vserver rss limit's to limit a guest's memory.
CGROUP Support is only build in for CPU hard cfs.

Best regards

Oliver
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.14 (GNU/Linux)

iEYEARECAAYFAkvlnCsACgkQOBdlVlcPuhwtbgCffmhs1Oqs7YSR7niMLX4gonyL
XgkAoKRCcBqlqoOGDXjfeoImkNaHZaGx
=FvCj
-----END PGP SIGNATURE-----
Received on Sat May 8 18:15:38 2010

[Next/Previous Months] [Main vserver Project Homepage] [Howto Subscribe/Unsubscribe] [Paul Sladen's vserver stuff]
Generated on Sat 08 May 2010 - 18:15:41 BST by hypermail 2.1.8