[LU-6727] parallel-scale test mdtestfpp hung

• Type: Bug
• Resolution: Fixed
• Priority: Blocker
• Fix Version/s: Lustre 2.8.0
• Affects Version/s: Lustre 2.8.0
• Environment: Lustre Build: https://build.hpdd.intel.com/job/lustre-master/3059; Distro/Arch: RHEL7.1/x86_64 (server), SLES11SP3/x86_64 (client)
• Severity: 3
• Assignee: Alex Zhuravlev
• Reporter: Jian Yu

Description

Maloo report: https://testing.hpdd.intel.com/test_sets/4542545e-10e2-11e5-a4f9-5254006e85c2

Console log on MDS (shadow-2vm4):

[11694.671469] Lustre: DEBUG MARKER: /usr/sbin/lctl mark == parallel-scale test mdtestfpp: mdtestfpp ========================================================== 12:43:53 \(1434051833\)^M
[11695.035400] Lustre: DEBUG MARKER: == parallel-scale test mdtestfpp: mdtestfpp ========================================================== 12:43:53 (1434051833)^M
[12064.045003] BUG: soft lockup - CPU#1 stuck for 22s! [mdt00_006:31733]^M
[12064.045003] Modules linked in: osp(OF) mdd(OF) lod(OF) mdt(OF) lfsck(OF) mgs(OF) mgc(OF) osd_ldiskfs(OF) lquota(OF) fid(OF) fld(OF) ksocklnd(OF) ptlrpc(OF) obdclass(OF) lnet(OF) sha512_generic libcfs(OF) ldiskfs(OF) dm_mod nfsv3 nfs_acl rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver nfs lockd fscache xprtrdma sunrpc ib_isert iscsi_target_mod ib_iser libiscsi scsi_transport_iscsi ib_srpt target_core_mod ib_srp scsi_transport_srp scsi_tgt ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ppdev ib_sa pcspkr virtio_balloon serio_raw parport_pc parport i2c_piix4 ib_mad ib_core ib_addr ext4 mbcache jbd2 ata_generic pata_acpi cirrus virtio_blk syscopyarea sysfillrect sysimgblt drm_kms_helper ttm ata_piix drm 8139too virtio_pci 8139cp virtio_ring virtio mii i2c_core libata floppy^M
[12064.045003] CPU: 1 PID: 31733 Comm: mdt00_006 Tainted: GF          O--------------   3.10.0-229.4.2.el7_lustre.g1fee634.x86_64 #1^M
[12064.045003] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2007^M
[12064.045003] task: ffff880079498000 ti: ffff88004bd64000 task.ti: ffff88004bd64000^M
[12064.045003] RIP: 0010:[<ffffffffa0bc8b9c>]  [<ffffffffa0bc8b9c>] iam_insert_key_lock+0x2c/0x50 [osd_ldiskfs]^M
[12064.045003] RSP: 0018:ffff88004bd673d0  EFLAGS: 00000206^M
[12064.045003] RAX: 000000000231c029 RBX: ffff88007b1e7240 RCX: 00000000000000cc^M
[12064.045003] RDX: ffff8800120137fc RSI: ffff88004bd67500 RDI: ffff88004bd674c8^M
[12064.045003] RBP: ffff88004bd673d8 R08: ffff88005bfa23a8 R09: 0000000000000055^M
[12064.045003] R10: ffff880079ecd1c8 R11: 7d1b000002000000 R12: ffff88004bd67360^M
[12064.045003] R13: 0000000000000000 R14: ffff88005662b930 R15: ffffffffa05c4e87^M
[12064.045003] FS:  0000000000000000(0000) GS:ffff88007fd00000(0000) knlGS:0000000000000000^M
[12064.045003] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b^M
[12064.045003] CR2: 00007f3dc08ef000 CR3: 000000007874c000 CR4: 00000000000006e0^M
[12064.045003] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000^M
[12064.045003] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400^M
[12064.045003] Stack:^M
[12064.045003]  ffff88004bd675a8 ffff88004bd67430 ffffffffa0bcb582 ffff88004bd67478^M
[12064.045003]  ffff8800583c19c0 000000aa4bd6746c ffff880015727000 ffff88004bd674c8^M
[12064.045003]  ffff88007b1e7240 ffff88005d72a338 ffff88004bd675a8 ffff88005d72a360^M
[12064.045003] Call Trace:^M
[12064.045003]  [<ffffffffa0bcb582>] iam_lfix_split+0x122/0x140 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0bc9e16>] iam_add_rec+0x236/0x2f0 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0bcb5a0>] ? iam_lfix_split+0x140/0x140 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0bca77e>] iam_insert+0xce/0x120 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0bc2115>] osd_oi_iam_refresh.isra.16+0x125/0x2a0 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0bc44c7>] osd_oi_insert+0x147/0x490 [osd_ldiskfs]^M
[12064.045003]  [<ffffffff811eb4b2>] ? generic_setxattr+0x62/0x80^M
[12064.045003]  [<ffffffffa0bbf767>] osd_object_ea_create+0x527/0x980 [osd_ldiskfs]^M
[12064.045003]  [<ffffffffa0e4cebc>] lod_sub_object_create+0x22c/0x460 [lod]^M
[12064.045003]  [<ffffffffa0e4495f>] lod_object_create+0xaf/0x200 [lod]^M
[12064.045003]  [<ffffffffa0ea62e5>] mdd_object_create_internal+0xb5/0x280 [mdd]^M
[12064.045003]  [<ffffffffa0e91b96>] mdd_object_create+0x76/0xa20 [mdd]^M
[12064.045003]  [<ffffffffa0e9ac17>] ? mdd_declare_create+0x447/0xd30 [mdd]^M
[12064.045003]  [<ffffffffa0e9c1c0>] mdd_create+0xcc0/0x1260 [mdd]^M
[12064.045003]  [<ffffffffa0d8101b>] mdt_reint_open+0x1f4b/0x2da0 [mdt]^M
[12064.045003]  [<ffffffffa0784149>] ? upcall_cache_get_entry+0x3e9/0x8e0 [obdclass]^M
[12064.045003]  [<ffffffff812ddd72>] ? strlcpy+0x42/0x60^M
[12064.045003]  [<ffffffffa0d75920>] mdt_reint_rec+0x80/0x210 [mdt]^M
[12064.045003]  [<ffffffffa0d591ac>] mdt_reint_internal+0x58c/0x780 [mdt]^M
[12064.045003]  [<ffffffffa0d59502>] mdt_intent_reint+0x162/0x420 [mdt]^M
[12064.045003]  [<ffffffffa0d630ba>] mdt_intent_policy+0x58a/0xb80 [mdt]^M
[12064.045003]  [<ffffffffa0972103>] ldlm_lock_enqueue+0x353/0x930 [ptlrpc]^M
[12064.045003]  [<ffffffffa0999062>] ldlm_handle_enqueue0+0x4f2/0x1540 [ptlrpc]^M
[12064.045003]  [<ffffffffa09beeb0>] ? lustre_swab_ldlm_lock_desc+0x30/0x30 [ptlrpc]^M
[12064.045003]  [<ffffffffa0a14562>] tgt_enqueue+0x62/0x210 [ptlrpc]^M
[12064.045003]  [<ffffffffa0a18235>] tgt_request_handle+0x6d5/0x1060 [ptlrpc]^M
[12064.045003]  [<ffffffffa09c820b>] ptlrpc_server_handle_request+0x21b/0xa90 [ptlrpc]^M
[12064.045003]  [<ffffffffa09c5d88>] ? ptlrpc_wait_event+0x98/0x340 [ptlrpc]^M
[12064.045003]  [<ffffffff810a9662>] ? default_wake_function+0x12/0x20^M
[12064.045003]  [<ffffffff810a0898>] ? __wake_up_common+0x58/0x90^M
[12064.045003]  [<ffffffffa09cc3f8>] ptlrpc_main+0xaf8/0x1ea0 [ptlrpc]^M
[12064.045003]  [<ffffffff810ad8b6>] ? __dequeue_entity+0x26/0x40^M
[12064.045003]  [<ffffffff810125f6>] ? __switch_to+0x136/0x4a0^M
[12064.045003]  [<ffffffffa09cb900>] ? ptlrpc_register_service+0xf00/0xf00 [ptlrpc]^M
[12064.045003]  [<ffffffff8109739f>] kthread+0xcf/0xe0^M
[12064.045003]  [<ffffffff810972d0>] ? kthread_create_on_node+0x140/0x140^M
[12064.045003]  [<ffffffff81614f7c>] ret_from_fork+0x7c/0xb0^M
[12064.045003]  [<ffffffff810972d0>] ? kthread_create_on_node+0x140/0x140^M
[12064.045003] Code: 1f 44 00 00 55 48 89 e5 53 4c 8b 06 48 89 f3 f0 41 0f ba 28 19 19 c0 85 c0 74 12 0f 1f 40 00 49 8b 00 a9 00 00 00 02 74 e6 f3 90 <eb> f2 48 89 de e8 2a ff ff ff 48 8b 1b e8 22 7a 4d e0 f0 80 63 ^M
[12064.045003] Kernel panic - not syncing: softlockup: hung tasks^M

Please find more console logs in the attached file.