[LU-2451] recovery-small test_24b: BUG: soft lockup - CPU#0 stuck for 67s! [ll_imp_inval:4791]

• Type: Bug
• Resolution: Duplicate
• Priority: Blocker
• Affects Version/s: Lustre 2.1.4
• Environment: Lustre Branch: b2_1; Lustre Build: http://build.whamcloud.com/job/lustre-b2_1/148; Distro/Arch: RHEL6.3/x86_64 (kernel version: 2.6.32-279.14.1.el6); Network: TCP (1GigE)
• Severity: 3
• Assignee: Niu Yawei (Inactive)
• Reporter: Jian Yu

Description

The recovery-small test 24b hung due to the following soft lockup issue on client:

18:45:08:Lustre: DEBUG MARKER: == recovery-small test 24b: test dirty page discard due to client eviction == 18:45:02 (1354934702)
18:45:08:Lustre: DEBUG MARKER: cancel_lru_locks osc start
18:45:08:Lustre: DEBUG MARKER: cancel_lru_locks osc stop
18:45:08:LustreError: 11-0: an error occurred while communicating with 10.10.4.151@tcp. The ost_write operation failed with -107
18:45:08:LustreError: 167-0: This client was evicted by lustre-OST0000; in progress operations using this service will fail.
18:45:09:Lustre: 20511:0:(llite_lib.c:2285:ll_dirty_page_discard_warn()) dirty page discard: 10.10.4.150@tcp:/lustre/fid: [0x200000401:0x42:0x0]//d0.recovery-small/d24/f24b-1 may get corrupted (rc -4)
18:45:09:LustreError: 20511:0:(client.c:1060:ptlrpc_import_delay_req()) @@@ IMP_INVALID  req@ffff88007b678c00 x1420751262452328/t0(0) o4->lustre-OST0000-osc-ffff88007b271800@10.10.4.151@tcp:6/4 lens 456/416 e 0 to 0 dl 0 ref 2 fl Rpc:/0/ffffffff rc 0/-1
18:46:20:BUG: soft lockup - CPU#0 stuck for 67s! [ll_imp_inval:4791]
18:46:20:Modules linked in: lustre(U) mgc(U) lov(U) osc(U) mdc(U) lmv(U) fid(U) fld(U) lquota(U) ptlrpc(U) obdclass(U) lvfs(U) ksocklnd(U) lnet(U) libcfs(U) nfs fscache nfsd lockd nfs_acl auth_rpcgss exportfs autofs4 sunrpc ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_addr ipv6 ib_sa ib_mad ib_core microcode virtio_balloon 8139too 8139cp mii i2c_piix4 i2c_core ext3 jbd mbcache 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]
18:46:22:CPU 0 
18:46:22:Modules linked in: lustre(U) mgc(U) lov(U) osc(U) mdc(U) lmv(U) fid(U) fld(U) lquota(U) ptlrpc(U) obdclass(U) lvfs(U) ksocklnd(U) lnet(U) libcfs(U) nfs fscache nfsd lockd nfs_acl auth_rpcgss exportfs autofs4 sunrpc ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_addr ipv6 ib_sa ib_mad ib_core microcode virtio_balloon 8139too 8139cp mii i2c_piix4 i2c_core ext3 jbd mbcache 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]
18:46:22:
18:46:22:Pid: 4791, comm: ll_imp_inval Not tainted 2.6.32-279.14.1.el6.x86_64 #1 Red Hat KVM
18:46:22:RIP: 0010:[<ffffffff8150098e>]  [<ffffffff8150098e>] _spin_lock+0x1e/0x30
18:46:22:RSP: 0018:ffff88007b60de00  EFLAGS: 00000206
18:46:22:RAX: 0000000000000001 RBX: ffff88007b60de00 RCX: 0000000000000000
18:46:22:RDX: 0000000000000000 RSI: ffffffffa04dfce6 RDI: ffff88007c616734
18:46:22:RBP: ffffffff8100bc0e R08: 00000000ffffff0a R09: 0000000000000000
18:46:23:R10: 000000000000000f R11: 000000000000000f R12: 0000000000000010
18:46:23:R13: ffffffffa0848ef1 R14: ffff88007b60ddc0 R15: 0000000000000000
18:46:24:FS:  00007f65fc14a700(0000) GS:ffff880002200000(0000) knlGS:0000000000000000
18:46:24:CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
18:46:24:CR2: 000000000208b3c0 CR3: 000000003796c000 CR4: 00000000000006f0
18:46:24:DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
18:46:24:DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
18:46:24:Process ll_imp_inval (pid: 4791, threadinfo ffff88007b60c000, task ffff88007b90b500)
18:46:24:Stack:
18:46:24: ffff88007b60de60 ffffffffa090dead 0000000000000010 ffff880000808003
18:46:24:<d> ffff88007b60de30 000000018109252c ffff88007b60de60 ffff880076109800
18:46:24:<d> ffff88007c616138 ffffffff00000100 ebc0de0100000000 0000000000004e1a
18:46:24:Call Trace:
18:46:25: [<ffffffffa090dead>] ? osc_import_event+0x3ad/0x1470 [osc]
18:46:25: [<ffffffffa0687b01>] ? ptlrpc_invalidate_import+0x2d1/0x910 [ptlrpc]
18:46:25: [<ffffffff810602c0>] ? default_wake_function+0x0/0x20
18:46:25: [<ffffffff811abaef>] ? unshare_fs_struct+0x5f/0xb0
18:46:25: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:25: [<ffffffffa06883af>] ? ptlrpc_invalidate_import_thread+0x4f/0x2f0 [ptlrpc]
18:46:25: [<ffffffff8100c14a>] ? child_rip+0xa/0x20
18:46:25: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:25: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:25: [<ffffffff8100c140>] ? child_rip+0x0/0x20
18:46:26:Code: 00 00 00 01 74 05 e8 62 e0 d7 ff c9 c3 55 48 89 e5 0f 1f 44 00 00 b8 00 00 01 00 3e 0f c1 07 0f b7 d0 c1 e8 10 39 c2 74 0e f3 90 <0f> 1f 44 00 00 83 3f 00 75 f4 eb df c9 c3 0f 1f 40 00 55 48 89 
18:46:26:Call Trace:
18:46:26: [<ffffffffa090dead>] ? osc_import_event+0x3ad/0x1470 [osc]
18:46:26: [<ffffffffa0687b01>] ? ptlrpc_invalidate_import+0x2d1/0x910 [ptlrpc]
18:46:26: [<ffffffff810602c0>] ? default_wake_function+0x0/0x20
18:46:26: [<ffffffff811abaef>] ? unshare_fs_struct+0x5f/0xb0
18:46:26: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:26: [<ffffffffa06883af>] ? ptlrpc_invalidate_import_thread+0x4f/0x2f0 [ptlrpc]
18:46:26: [<ffffffff8100c14a>] ? child_rip+0xa/0x20
18:46:27: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:27: [<ffffffffa0688360>] ? ptlrpc_invalidate_import_thread+0x0/0x2f0 [ptlrpc]
18:46:27: [<ffffffff8100c140>] ? child_rip+0x0/0x20

Maloo report: https://maloo.whamcloud.com/test_sets/1d70d272-41da-11e2-adcf-52540035b04c

Issue Links

• duplicates: LU-2505 lfsck: BUG: soft lockup - CPU#0 stuck for 67s! [umount:22194]