[LU-2360] lockups reading req_history

• Type: Bug
• Resolution: Fixed
• Priority: Blocker
• Fix Version/s: Lustre 2.4.0
• Affects Version/s: Lustre 2.4.0
• Labels: MB
• Assignee: John Hammond
• Reporter: John Hammond

Description

Reading the req_history files on an llmount.sh FS reproducibly wedges the system.

# find /proc/fs/lustre/ -name req_history -print -exec wc -l {} \;
/proc/fs/lustre/ldlm/services/ldlm_canceld/req_history

BUG: soft lockup - CPU#0 stuck for 67s! [wc:27808]
Modules linked in: lustre(U) ofd(U) osp(U) lod(U) ost(U) mdt(U) osd_ldiskfs(U) fsfilt_ldiskfs(U) ldiskfs(U) mdd(U) mgs(U) lquota(U) obdecho(U) mgc(U) lov(U) osc(U) mdc(U) lmv(U) fid(U) fld(U) ptlrpc(U) obdclass(U) lvfs(U) ksocklnd(U) lnet(U) libcfs(U) bridge stp llc exportfs jbd sha512_generic sha256_generic autofs4 nfs lockd fscache nfs_acl auth_rpcgss sunrpc ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 microcode virtio_balloon virtio_net i2c_piix4 i2c_core ext4 mbcache jbd2 virtio_blk virtio_pci virtio_ring virtio pata_acpi ata_generic ata_piix dm_mirror dm_region_hash dm_log dm_mod [last unloaded: libcfs]
irq event stamp: 0
hardirqs last enabled at (0): [<(null)>] (null)
hardirqs last disabled at (0): [<ffffffff8106cf94>] copy_process+0x604/0x15d0
softirqs last enabled at (0): [<ffffffff8106cf94>] copy_process+0x604/0x15d0
softirqs last disabled at (0): [<(null)>] (null)
CPU 0
Modules linked in: lustre(U) ofd(U) osp(U) lod(U) ost(U) mdt(U) osd_ldiskfs(U) fsfilt_ldiskfs(U) ldiskfs(U) mdd(U) mgs(U) lquota(U) obdecho(U) mgc(U) lov(U) osc(U) mdc(U) lmv(U) fid(U) fld(U) ptlrpc(U) obdclass(U) lvfs(U) ksocklnd(U) lnet(U) libcfs(U) bridge stp llc exportfs jbd sha512_generic sha256_generic autofs4 nfs lockd fscache nfs_acl auth_rpcgss sunrpc ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 microcode virtio_balloon virtio_net i2c_piix4 i2c_core ext4 mbcache jbd2 virtio_blk virtio_pci virtio_ring virtio pata_acpi ata_generic ata_piix dm_mirror dm_region_hash dm_log dm_mod [last unloaded: libcfs]

Pid: 27808, comm: wc Not tainted 2.6.32-279.11.1.el6.lm.x86_64 #1 Bochs Bochs
RIP: 0010:[<ffffffffa0fc027d>] [<ffffffffa0fc027d>] ptlrpc_lprocfs_svc_req_history_seek+0x5d/0x130 [ptlrpc]
RSP: 0018:ffff8801f5b15db8 EFLAGS: 00000202
RAX: ffff8801f29085b8 RBX: ffff8801f5b15dc8 RCX: ffff8801f2908590
RDX: 50aab97485500001 RSI: ffff8801ef5425a8 RDI: 50aab97485340000
RBP: ffffffff8100bcce R08: ffff880214b4dab0 R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
R13: ffff88002f800000 R14: ffff8801f5b14000 R15: 0000000000000000
FS: 00007fa0f02cf700(0000) GS:ffff88002f800000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fff2a2aa1ec CR3: 00000001ea6cb000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process wc (pid: 27808, threadinfo ffff8801f5b14000, task ffff8801dc075340)
Stack:
ffff8801ef5425a8 0000000000000001 ffff8801f5b15e18 ffffffffa0fc0429
<d> 00050aab95b00078 ffff880214b4d9a8 00007fff2a2aa220 ffff8801f5beca48
<d> ffff88021660b128 ffff8801ef5425a8 0000000000000057 ffff8801f5b15e58
Call Trace:
[<ffffffffa0fc0429>] ? ptlrpc_lprocfs_svc_req_history_next+0x79/0x190 [ptlrpc]
[<ffffffff811babd5>] ? seq_read+0x265/0x420
[<ffffffff811ba970>] ? seq_read+0x0/0x420
[<ffffffff811fee95>] ? proc_reg_read+0x85/0xc0
[<ffffffff81197f55>] ? vfs_read+0xb5/0x1a0
[<ffffffff810e7f6a>] ? audit_syscall_entry+0x26a/0x290
[<ffffffff81198091>] ? sys_read+0x51/0x90
[<ffffffff8100b0b2>] ? system_call_fastpath+0x16/0x1b
Code: 01 00 00 4c 39 87 08 01 00 00 0f 84 86 00 00 00 48 83 c0 28 eb 18 0f 1f 84 00 00 00 00 00 48 8d 48 d8 48 8b 79 58 48 39 fa 76 13 <48> 8b 00 49 39 c0 75 eb b8 fe ff ff ff c9 c3 0f 1f 40 00 48 89
Call Trace:
[<ffffffff815319eb>] ? _spin_unlock+0x2b/0x40
[<ffffffffa0fc0429>] ? ptlrpc_lprocfs_svc_req_history_next+0x79/0x190 [ptlrpc]
[<ffffffff811babd5>] ? seq_read+0x265/0x420
[<ffffffff811ba970>] ? seq_read+0x0/0x420
[<ffffffff811fee95>] ? proc_reg_read+0x85/0xc0
[<ffffffff81197f55>] ? vfs_read+0xb5/0x1a0
[<ffffffff810e7f6a>] ? audit_syscall_entry+0x26a/0x290
[<ffffffff81198091>] ? sys_read+0x51/0x90
[<ffffffff8100b0b2>] ? system_call_fastpath+0x16/0x1b

Issue Links

• is duplicated by: LU-2510 general protection fault (ptlrpc_lprocfs_svc_req_history_seek+0x54/0x130) caused by " /proc/fs/lustre/mds/MDS/*/req_history"