[LU-1827] Test failure on test suite racer, subtest test_1

• Type: Bug
• Resolution: Cannot Reproduce
• Priority: Minor
• Affects Version/s: Lustre 2.3.0
• Severity: 3
• Assignee: WC Triage
• Reporter: Maloo

Description

This issue was created by maloo for sarah <[e-mail]>

This issue relates to the following test suite run: https://maloo.whamcloud.com/test_sets/0e93917a-f43e-11e1-8032-52540035b04c.

The sub-test test_1 failed with the following error:

test failed to respond and timed out

04:04:38:Lustre: DEBUG MARKER: == racer test 1: racer on clients: client-25vm5,client-25vm6.lab.whamcloud.com DURATION=900 == 04:04:36 (1346411076)
04:04:38:Lustre: DEBUG MARKER: PATH=/usr/lib64/lustre/tests:/usr/lib/lustre/tests:/usr/lib64/lustre/tests:/opt/iozone/bin:/opt/iozone/bin:/usr/lib64/lustre/tests/mpi:/usr/lib64/lustre/tests/racer:/usr/lib64/lustre/../lustre-iokit/sgpdd-survey:/usr/lib64/lustre/tests:/usr/lib64/lustre/u
04:04:38:Lustre: DEBUG MARKER: DURATION=900 /usr/lib64/lustre/tests/racer/racer.sh /mnt/lustre2/racer 
04:04:38:Lustre: DEBUG MARKER: DURATION=900 /usr/lib64/lustre/tests/racer/racer.sh /mnt/lustre/racer 
04:05:34:LustreError: 11-0: an error occurred while communicating with 10.10.4.142@tcp. The mds_getattr operation failed with -2
04:08:58:LustreError: 11-0: an error occurred while communicating with 10.10.4.142@tcp. The mds_getattr operation failed with -2
04:10:25:LustreError: 11-0: an error occurred while communicating with 10.10.4.142@tcp. The mds_getattr operation failed with -2
04:15:54:BUG: soft lockup - CPU#0 stuck for 68s! [ls:29052]
04:15:55:Modules linked in: lustre(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) ext2 sha512_generic sha256_generic 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]
04:15:55:CPU 0 
04:15:56:Modules linked in: lustre(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) ext2 sha512_generic sha256_generic 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]
04:15:56:
04:15:56:Pid: 29052, comm: ls Not tainted 2.6.32-279.5.1.el6.x86_64 #1 Red Hat KVM
04:15:56:RIP: 0010:[<ffffffff8150024e>]  [<ffffffff8150024e>] _spin_lock+0x1e/0x30
04:15:56:RSP: 0018:ffff88003f543a78  EFLAGS: 00000206
04:15:56:RAX: 0000000000000001 RBX: ffff88003f543a78 RCX: 0000000000000002
04:15:56:RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff8800490f5638
04:15:56:RBP: ffffffff8100bc0e R08: 00000000ffffff0a R09: 00000000fffffff8
04:15:56:R10: 0000000000000006 R11: 0000000000000002 R12: 0000000000098800
04:15:56:R13: ffff8800490f5378 R14: ffffffff8119439e R15: ffff88003f543a18
04:15:56:FS:  00007fd9c870f7a0(0000) GS:ffff880002200000(0000) knlGS:0000000000000000
04:15:56:CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
04:15:56:CR2: 00007f726983d008 CR3: 0000000049120000 CR4: 00000000000006f0
04:15:56:DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
04:15:56:DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
04:15:57:Process ls (pid: 29052, threadinfo ffff88003f542000, task ffff88000d37aae0)
04:15:57:Stack:
04:15:57: ffff88003f543b58 ffffffffa0a43d73 ffff88003f543b18 ffffffffa0a68ef5
04:15:57:<d> ffff88003f543bc0 ffffffffa0a6a510 0000000000000000 ffffffffa0a6a45e
04:15:57:<d> ffff8800462f5a00 0000000000000000 ffff8800462f5a00 ffff88002d0204c0
04:15:57:Call Trace:
04:15:57: [<ffffffffa0a43d73>] ? ll_file_open+0x533/0xca0 [lustre]
04:15:57: [<ffffffffa0a68ef5>] ? ll_lookup_it_finish+0x85/0x9d0 [lustre]
04:15:57: [<ffffffffa0a6a510>] ? ll_md_blocking_ast+0x0/0x780 [lustre]
04:15:57: [<ffffffffa0a6a45e>] ? ll_i2gids+0x2e/0xe0 [lustre]
04:15:57: [<ffffffffa0a69c9e>] ? ll_lookup_it+0x45e/0xbc0 [lustre]
04:15:57: [<ffffffffa0a2b5d0>] ? ll_dir_open+0x0/0xf0 [lustre]
04:15:57: [<ffffffffa0a2b6ab>] ? ll_dir_open+0xdb/0xf0 [lustre]
04:15:57: [<ffffffff811789ba>] ? __dentry_open+0x10a/0x360
04:15:57: [<ffffffffa04e6be0>] ? cfs_alloc+0x30/0x60 [libcfs]
04:15:57: [<ffffffff81178da9>] ? lookup_instantiate_filp+0x69/0x90
04:15:57: [<ffffffffa0a6b4de>] ? ll_lookup_nd+0xfe/0x400 [lustre]
04:15:57: [<ffffffff81193cc7>] ? d_alloc+0x137/0x1b0
04:15:57: [<ffffffff81189725>] ? do_lookup+0x1a5/0x230
04:15:58: [<ffffffff81189fe4>] ? __link_path_walk+0x734/0x1030
04:15:58: [<ffffffff8118ab6a>] ? path_walk+0x6a/0xe0
04:15:58: [<ffffffff8118ad3b>] ? do_path_lookup+0x5b/0xa0
04:15:58: [<ffffffff8117c780>] ? get_empty_filp+0xa0/0x180
04:15:58: [<ffffffff8118bc6b>] ? do_filp_open+0xfb/0xd60
04:15:58: [<ffffffff8119a460>] ? mntput_no_expire+0x30/0x110
04:15:58: [<ffffffff811982b2>] ? alloc_fd+0x92/0x160
04:15:59: [<ffffffff81178769>] ? do_sys_open+0x69/0x140
04:15:59: [<ffffffff81178880>] ? sys_open+0x20/0x30
04:15:59: [<ffffffff8100b0f2>] ? system_call_fastpath+0x16/0x1b
04:15:59:Code: 00 00 00 01 74 05 e8 b2 e3 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 
04:15:59:Call Trace:
04:15:59: [<ffffffffa0a43d73>] ? ll_file_open+0x533/0xca0 [lustre]
04:15:59: [<ffffffffa0a68ef5>] ? ll_lookup_it_finish+0x85/0x9d0 [lustre]
04:15:59: [<ffffffffa0a6a510>] ? ll_md_blocking_ast+0x0/0x780 [lustre]
04:15:59: [<ffffffffa0a6a45e>] ? ll_i2gids+0x2e/0xe0 [lustre]
04:15:59: [<ffffffffa0a69c9e>] ? ll_lookup_it+0x45e/0xbc0 [lustre]
04:15:59: [<ffffffffa0a2b5d0>] ? ll_dir_open+0x0/0xf0 [lustre]
04:16:00: [<ffffffffa0a2b6ab>] ? ll_dir_open+0xdb/0xf0 [lustre]
04:16:00: [<ffffffff811789ba>] ? __dentry_open+0x10a/0x360
04:16:00: [<ffffffffa04e6be0>] ? cfs_alloc+0x30/0x60 [libcfs]
04:16:00: [<ffffffff81178da9>] ? lookup_instantiate_filp+0x69/0x90
04:16:00: [<ffffffffa0a6b4de>] ? ll_lookup_nd+0xfe/0x400 [lustre]
04:16:00: [<ffffffff81193cc7>] ? d_alloc+0x137/0x1b0
04:16:00: [<ffffffff81189725>] ? do_lookup+0x1a5/0x230
04:16:00: [<ffffffff81189fe4>] ? __link_path_walk+0x734/0x1030
04:16:00: [<ffffffff8118ab6a>] ? path_walk+0x6a/0xe0
04:16:00: [<ffffffff8118ad3b>] ? do_path_lookup+0x5b/0xa0
04:16:00: [<ffffffff8117c780>] ? get_empty_filp+0xa0/0x180
04:16:00: [<ffffffff8118bc6b>] ? do_filp_open+0xfb/0xd60
04:16:00: [<ffffffff8119a460>] ? mntput_no_expire+0x30/0x110
04:16:00: [<ffffffff811982b2>] ? alloc_fd+0x92/0x160
04:16:00: [<ffffffff81178769>] ? do_sys_open+0x69/0x140
04:16:00: [<ffffffff81178880>] ? sys_open+0x20/0x30
04:16:00: [<ffffffff8100b0f2>] ? system_call_fastpath+0x16/0x1b