Open Stack

On 01/05/2015 03:46 PM, Matej Mailing wrote:
> Hello Erhan,
> 
> soft lock-up has just happened again on the instance node. I am
> monitoring network interface traffic on which the NFS server is
> connected and the interface has constantly been under 20% of it's
> capacity, also the load on the NFS server is load - though I am unsure
> if this is relevant at all...
> 
> What makes me wonder - is is "normal" that both lock-ups are for the
> same period of time (51s) even on two CPUs and with two different
> PIDs?
> 
> The output from the log is:
> 
> Jan  5 11:01:13 postar kernel: [477123.485080] NMI watchdog: BUG: soft
> lockup - CPU#3 stuck for 51s! [mysqld:2612]
> Jan  5 11:01:13 postar kernel: [477123.485151] Modules linked in:
> xt_hl ip6t_rt nf_conntrack_ipv6 nf_defrag_ipv6 ipt_REJECT
> nf_reject_ipv4 xt_limit
> xt_tcpudp xt_addrtype nf_conntrack_ipv4 nf_defrag_ipv4 xt_state
> ip6table_filter ip6_tables nfsd nfs_acl auth_rpcgss
> nf_conntrack_netbios_ns
> nf_conntrack_broadcast nfs nf_nat_ftp nf_nat ppdev nf_conntrack_ftp
> nf_conntrack fscache parport_pc parport lockd joydev pvpanic
> iptable_filter cirrus
> ip_tables 8250_fintek ttm psmouse drm_kms_helper sunrpc x_tables
> serio_raw hid_generic drm grace mac_hid sysimgblt sysfillrect
> syscopyarea i2c_piix4
> usbhid hid floppy
> Jan  5 11:01:13 postar kernel: [477123.485200] CPU: 3 PID: 2612 Comm:
> mysqld Tainted: G             L 3.18.1-031801-generic #201412170637
> Jan  5 11:01:13 postar kernel: [477123.485202] Hardware name:
> OpenStack Foundation OpenStack Nova, BIOS Bochs 01/01/2011
> Jan  5 11:01:13 postar kernel: [477123.485205] task: ffff880037ab6400
> ti: ffff880206e40000 task.ti: ffff880206e40000
> Jan  5 11:01:13 postar kernel: [477123.485207] RIP:
> 0010:[<ffffffff813a97dc>]  [<ffffffff813a97dc>]
> copy_user_generic_string+0x2c/0x40
> Jan  5 11:01:13 postar kernel: [477123.485217] RSP:
> 0018:ffff880206e43c90  EFLAGS: 00010246
> Jan  5 11:01:13 postar kernel: [477123.485219] RAX: 0000000076793000
> RBX: ffff880206e43ea0 RCX: 0000000000000200
> Jan  5 11:01:13 postar kernel: [477123.485221] RDX: 0000000000000000
> RSI: ffff880076793000 RDI: 00007fd365448000
> Jan  5 11:01:13 postar kernel: [477123.485223] RBP: ffff880206e43d08
> R08: ffffea0001d9e4dc R09: ffff880206e43ca0
> Jan  5 11:01:13 postar kernel: [477123.485225] R10: ffff8801b76ca6f0
> R11: 0000000000000293 R12: 0000000000000000
> Jan  5 11:01:13 postar kernel: [477123.485227] R13: ffff880206e43ec8
> R14: 0000000000001000 R15: 00007fd365448000
> Jan  5 11:01:13 postar kernel: [477123.485235] FS:
> 00007fd36c1fb700(0000) GS:ffff88023fd80000(0000)
> knlGS:0000000000000000
> Jan  5 11:01:13 postar kernel: [477123.485237] CS:  0010 DS: 0000 ES:
> 0000 CR0: 0000000080050033
> Jan  5 11:01:13 postar kernel: [477123.485239] CR2: 000000000b416003
> CR3: 00000002317ee000 CR4: 00000000000006e0
> Jan  5 11:01:13 postar kernel: [477123.485253] Stack:
> Jan  5 11:01:13 postar kernel: [477123.485255]  ffffffff811a0f75
> 000000000012f2ac ffff8801b76ca6f0 ffff880206e43cc8
> Jan  5 11:01:13 postar kernel: [477123.485259]  ffffffff8117864e
> ffff880076793000 ffffea0001d9e4c0 0000000000001000
> Jan  5 11:01:13 postar kernel: [477123.485262]  ffff880076793000
> ffffea0001d9e4c0 ffffea0001d9e4c0 ffff880231e4b930
> Jan  5 11:01:13 postar kernel: [477123.485265] Call Trace:
> Jan  5 11:01:13 postar kernel: [477123.485273]  [<ffffffff811a0f75>] ?
> copy_page_to_iter_iovec+0xe5/0x300
> Jan  5 11:01:13 postar kernel: [477123.485279]  [<ffffffff8117864e>] ?
> find_get_entry+0x1e/0x90
> Jan  5 11:01:13 postar kernel: [477123.485282]  [<ffffffff811a14a6>]
> copy_page_to_iter+0x16/0x70
> Jan  5 11:01:13 postar kernel: [477123.485286]  [<ffffffff81179428>]
> do_generic_file_read+0x1f8/0x490
> Jan  5 11:01:13 postar kernel: [477123.485289]  [<ffffffff8117a234>]
> generic_file_read_iter+0xf4/0x150
> Jan  5 11:01:13 postar kernel: [477123.485294]  [<ffffffff810aade1>] ?
> update_curr+0x141/0x1f0
> Jan  5 11:01:13 postar kernel: [477123.485298]  [<ffffffff811eef28>]
> new_sync_read+0x78/0xb0
> Jan  5 11:01:13 postar kernel: [477123.485301]  [<ffffffff811f013b>]
> vfs_read+0xab/0x180
> Jan  5 11:01:13 postar kernel: [477123.485304]  [<ffffffff811f0402>]
> SyS_pread64+0x92/0xa0
> Jan  5 11:01:13 postar kernel: [477123.485309]  [<ffffffff817b376d>]
> system_call_fastpath+0x16/0x1b
> Jan  5 11:01:13 postar kernel: [477123.485311] Code: 66 90 83 fa 08 72
> 27 89 f9 83 e1 07 74 15 83 e9 08 f7 d9 29 ca 8a 06 88 07 48 ff c6 48
> ff c7 ff c9 75 f$
> Jan  5 11:01:13 postar kernel: [477123.486574] NMI watchdog: BUG: soft
> lockup - CPU#1 stuck for 51s! [mysqld:2282]
> Jan  5 11:01:13 postar kernel: [477123.486633] Modules linked in:
> xt_hl ip6t_rt nf_conntrack_ipv6 nf_defrag_ipv6 ipt_REJECT
> nf_reject_ipv4 xt_limit xt_tcpud$
> Jan  5 11:01:13 postar kernel: [477123.486669] CPU: 1 PID: 2282 Comm:
> mysqld Tainted: G             L 3.18.1-031801-generic #201412170637
> Jan  5 11:01:13 postar kernel: [477123.486671] Hardware name:
> OpenStack Foundation OpenStack Nova, BIOS Bochs 01/01/2011
> Jan  5 11:01:13 postar kernel: [477123.486673] task: ffff880232bbb200
> ti: ffff880232bd8000 task.ti: ffff880232bd8000
> Jan  5 11:01:13 postar kernel: [477123.486675] RIP:
> 0010:[<ffffffff813a97dc>]  [<ffffffff813a97dc>]
> copy_user_generic_string+0x2c/0x40
> Jan  5 11:01:13 postar kernel: [477123.486680] RSP:
> 0018:ffff880232bdbc18  EFLAGS: 00010246
> Jan  5 11:01:13 postar kernel: [477123.486683] RAX: 00007fd35f714000
> RBX: 0000000000001000 RCX: 0000000000000200
> Jan  5 11:01:13 postar kernel: [477123.486685] RDX: 0000000000000000
> RSI: 00007fd35f714000 RDI: ffff88007131c000
> Jan  5 11:01:13 postar kernel: [477123.486687] RBP: ffff880232bdbc28
> R08: ffffea0001c4c700 R09: 00000000fffff000
> Jan  5 11:01:13 postar kernel: [477123.486689] R10: ffff8801b77814e0
> R11: 0000000000000293 R12: 0000000000001000
> Jan  5 11:01:13 postar kernel: [477123.486691] R13: ffff880232bdbea0
> R14: 0000000000000000 R15: 0000000000001000
> Jan  5 11:01:13 postar kernel: [477123.486697] FS:
> 00007fd35afe7700(0000) GS:ffff88023fc80000(0000)
> knlGS:0000000000000000
> Jan  5 11:01:13 postar kernel: [477123.486699] CS:  0010 DS: 0000 ES:
> 0000 CR0: 0000000080050033
> Jan  5 11:01:13 postar kernel: [477123.486702] CR2: 000000000cdc3001
> CR3: 00000002317ee000 CR4: 00000000000006e0
> Jan  5 11:01:13 postar kernel: [477123.486714] Stack:
> Jan  5 11:01:13 postar kernel: [477123.486716]  ffffffff811a0386
> 0000000120094000 ffff880232bdbc78 ffffffff811a0a35
> Jan  5 11:01:13 postar kernel: [477123.486719]  ffff880232bdbc88
> 0000000000000000 ffff880232bdbc78 0000000120094000
> Jan  5 11:01:13 postar kernel: [477123.486722]  0000000000001000
> ffff880232bdbea0 ffff880231e4b930 0000000000000000
> Jan  5 11:01:13 postar kernel: [477123.486726] Call Trace:
> Jan  5 11:01:13 postar kernel: [477123.486752]  [<ffffffff811a0386>] ?
> copy_from_user_atomic_iovec+0x56/0x80
> Jan  5 11:01:13 postar kernel: [477123.486757]  [<ffffffff811a0a35>]
> iov_iter_copy_from_user_atomic+0xd5/0xe0
> Jan  5 11:01:13 postar kernel: [477123.486761]  [<ffffffff81177410>]
> generic_perform_write+0xe0/0x1c0
> Jan  5 11:01:13 postar kernel: [477123.486766]  [<ffffffff8120a0f1>] ?
> update_time+0x81/0xc0
> Jan  5 11:01:13 postar kernel: [477123.486770]  [<ffffffff8120e4a2>] ?
> mnt_clone_write+0x12/0x30
> Jan  5 11:01:13 postar kernel: [477123.486773]  [<ffffffff81179e9f>]
> __generic_file_write_iter+0x16f/0x350
> Jan  5 11:01:13 postar kernel: [477123.486778]  [<ffffffff8126b7d9>]
> ext4_file_write_iter+0x119/0x3d0
> Jan  5 11:01:13 postar kernel: [477123.486783]  [<ffffffff810efcd8>] ?
> get_futex_key+0x1f8/0x2e0
> Jan  5 11:01:13 postar kernel: [477123.486786]  [<ffffffff811ef0eb>]
> new_sync_write+0x7b/0xb0
> Jan  5 11:01:13 postar kernel: [477123.486789]  [<ffffffff811eff67>]
> vfs_write+0xc7/0x1f0
> Jan  5 11:01:13 postar kernel: [477123.486792]  [<ffffffff811f04a2>]
> SyS_pwrite64+0x92/0xa0
> Jan  5 11:01:13 postar kernel: [477123.486795]  [<ffffffff817b376d>]
> system_call_fastpath+0x16/0x1b
> Jan  5 11:01:13 postar kernel: [477123.486797] Code: 66 90 83 fa 08 72
> 27 89 f9 83 e1 07 74 15 83 e9 08 f7 d9 29 ca 8a 06 88 07 48 ff c6 48
> ff c7 ff c9
> 75 f2 89 d1 c1 e9 03 83 e2 07 <f3> 48 a5 89 d1 f3 a4 31 c0 66 66 90 c3
> 0f 1f 80 00 00 00 00 66
> 
> 
> Thanks,
> Matej


The profile of this hardware looks virtualized. That makes me ask if you
have installed the para-virtualized drivers ?


-- 
Given the large number of mailing lists I follow, I request you to CC me
in replies for quicker response