Details
-
Bug
-
Resolution: Fixed
-
Critical
-
Lustre 2.9.0, Lustre 2.10.0
-
Soak test cluster. Lustre 2.9.0 GA Release
-
3
-
9223372036854775807
Description
This looks like a few bugs we've seen before, but not enough like any specific one.
- Started soak
- Started and completed router delay fault
- LFSCK triggered.
- LFSCK dones not complete, runs > 1905s
MGS/MDS0 has soft lockup on CPU.Jan 19 14:06:24 lola-8 kernel: BUG: soft lockup - CPU#9 stuck for 67s! [OI_scrub:19279] Jan 19 14:06:24 lola-8 kernel: Modules linked in: osp(U) mdd(U) lod(U) mdt(U) lfsck(U) mgs(U) mgc(U) osd_ldiskfs(U) lquota(U) lustre(U) lov(U) mdc(U) fid(U) lmv(U) fld(U) ko2iblnd(U) ptlrpc(U) obdclass(U) lnet(U) sha512_generic crc32c_intel libcfs(U) ldiskfs(U) jbd2 8021q garp stp llc nfsd exportfs nfs lockd fscache auth_rpcgss nfs_acl sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm scsi_dh_rdac dm_round_robin dm_multipath microcode iTCO_wdt iTCO_vendor_support zfs(P)(U) zcommon(P)(U) znvpair(P)(U) spl(U) zlib_deflate zavl(P)(U) zunicode(P)(U) joydev sb_edac edac_core lpc_ich mfd_core i2c_i801 ioatdma sg igb dca i2c_algo_bit i2c_core ext3 jbd mbcache sd_mod crc_t10dif ahci isci libsas wmi mpt2sas scsi_transport_sas raid_class mlx4_ib ib_sa ib_mad ib_core ib_addr ipv6 mlx4_en ptp pps_core mlx4_core dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan] Jan 19 14:06:24 lola-8 kernel: CPU 9 Jan 19 14:06:24 lola-8 kernel: Modules linked in: osp(U) mdd(U) lod(U) mdt(U) lfsck(U) mgs(U) mgc(U) osd_ldiskfs(U) lquota(U) lustre(U) lov(U) mdc(U) fid(U) lmv(U) fld(U) ko2iblnd(U) ptlrpc(U) obdclass(U) lnet(U) sha512_generic crc32c_intel libcfs(U) ldiskfs(U) jbd2 8021q garp stp llc nfsd exportfs nfs lockd fscache auth_rpcgss nfs_acl sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm scsi_dh_rdac dm_round_robin dm_multipath microcode iTCO_wdt iTCO_vendor_support zfs(P)(U) zcommon(P)(U) znvpair(P)(U) spl(U) zlib_deflate zavl(P)(U) zunicode(P)(U) joydev sb_edac edac_core lpc_ich mfd_core i2c_i801 ioatdma sg igb dca i2c_algo_bit i2c_core ext3 jbd mbcache sd_mod crc_t10dif ahci isci libsas wmi mpt2sas scsi_transport_sas raid_class mlx4_ib ib_sa ib_mad ib_core ib_addr ipv6 mlx4_en ptp pps_core mlx4_core dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan] Jan 19 14:06:24 lola-8 kernel: Jan 19 14:06:24 lola-8 kernel: Pid: 19279, comm: OI_scrub Tainted: P --L------------ 2.6.32-573.26.1.el6_lustre.x86_64 #1 Intel Corporation S2600GZ ........../S2600GZ Jan 19 14:06:24 lola-8 kernel: RIP: 0010:[<ffffffffa10d1e2f>] [<ffffffffa10d1e2f>] osd_scrub_exec+0xf/0x1dc0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: RSP: 0018:ffff88049472bc20 EFLAGS: 00000282 Jan 19 14:06:24 lola-8 kernel: RAX: 0000000000000004 RBX: ffff88049472bd00 RCX: ffff8803ac48ced0 Jan 19 14:06:24 lola-8 kernel: RDX: ffff88049472bda0 RSI: ffff880216078000 RDI: ffff88038a74d000 Jan 19 14:06:24 lola-8 kernel: RBP: ffffffff8100bc0e R08: ffff88049472bdcf R09: 0000000000000004 Jan 19 14:06:24 lola-8 kernel: R10: ffff8803ac48cec0 R11: ffff8803ac48ced0 R12: ffffffff81fe6920 Jan 19 14:06:24 lola-8 kernel: R13: ffff8802a5151210 R14: ffff88038a74d000 R15: ffffffffa08549a8 Jan 19 14:06:24 lola-8 kernel: FS: 0000000000000000(0000) GS:ffff88044e420000(0000) knlGS:0000000000000000 Jan 19 14:06:24 lola-8 kernel: CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b Jan 19 14:06:24 lola-8 kernel: CR2: 0000003903673b90 CR3: 0000000001a8d000 CR4: 00000000000407e0 Jan 19 14:06:24 lola-8 kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 Jan 19 14:06:24 lola-8 kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Jan 19 14:06:24 lola-8 kernel: Process OI_scrub (pid: 19279, threadinfo ffff880494728000, task ffff880802c30ab0) Jan 19 14:06:24 lola-8 kernel: Stack: Jan 19 14:06:24 lola-8 kernel: ffff880216078000 ffff88038a74d000 ffffffffffffff02 ffffffffa10d3c9a Jan 19 14:06:24 lola-8 kernel: <d> 0000000000000010 0000000000000202 ffff88049472bc60 0000000000000018 Jan 19 14:06:24 lola-8 kernel: <d> ffff8803ac48cee0 0000000000000001 ffff8802160790e0 ffff880216079000 Jan 19 14:06:24 lola-8 kernel: Call Trace: Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d3c9a>] ? osd_scrub_next+0xba/0x4b0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d6ec9>] ? osd_inode_iteration+0x4c9/0xd80 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff81539b0e>] ? thread_return+0x4e/0x7d0 Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d1e20>] ? osd_scrub_exec+0x0/0x1dc0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d3be0>] ? osd_scrub_next+0x0/0x4b0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d8905>] ? osd_scrub_main+0x885/0xec0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff81067650>] ? default_wake_function+0x0/0x20 Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d8080>] ? osd_scrub_main+0x0/0xec0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff810a138e>] ? kthread+0x9e/0xc0 Jan 19 14:06:24 lola-8 kernel: [<ffffffff8100c28a>] ? child_rip+0xa/0x20 Jan 19 14:06:24 lola-8 kernel: [<ffffffff810a12f0>] ? kthread+0x0/0xc0 Jan 19 14:06:24 lola-8 kernel: [<ffffffff8100c280>] ? child_rip+0x0/0x20 Jan 19 14:06:24 lola-8 kernel: Code: 00 00 00 e8 54 fe 7b ff e9 14 ff ff ff 66 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 81 ec e0 00 00 00 48 89 5d d8 <4c> 89 65 e0 4c 89 6d e8 4c 89 75 f0 4c 89 7d f8 0f 1f 44 00 00 an 19 14:06:24 lola-8 kernel: Code: 00 00 00 e8 54 fe 7b ff e9 14 ff ff ff 66 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 81 ec e0 00 00 00 48 89 5d d8 <4c> 89 65 e0 4c 89 6d e8 4c 89 75 f0 4c 89 7d f8 0f 1f 44 00 00 Jan 19 14:06:24 lola-8 kernel: Call Trace: Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d3c9a>] ? osd_scrub_next+0xba/0x4b0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d6ec9>] ? osd_inode_iteration+0x4c9/0xd80 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff81539b0e>] ? thread_return+0x4e/0x7d0 Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d1e20>] ? osd_scrub_exec+0x0/0x1dc0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d3be0>] ? osd_scrub_next+0x0/0x4b0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d8905>] ? osd_scrub_main+0x885/0xec0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff81067650>] ? default_wake_function+0x0/0x20 Jan 19 14:06:24 lola-8 kernel: [<ffffffffa10d8080>] ? osd_scrub_main+0x0/0xec0 [osd_ldiskfs] Jan 19 14:06:24 lola-8 kernel: [<ffffffff810a138e>] ? kthread+0x9e/0xc0 Jan 19 14:06:24 lola-8 kernel: [<ffffffff8100c28a>] ? child_rip+0xa/0x20 Jan 19 14:06:24 lola-8 kernel: [<ffffffff810a12f0>] ? kthread+0x0/0xc0 Jan 19 14:06:24 lola-8 kernel: [<ffffffff8100c280>] ? child_rip+0x0/0x20
Attempting to get a stack dump, but not going well. System is available is anyone wishes to have a look
Attachments
Issue Links
![[Whamcloud Community Wiki] Page](/images/icons/generic_link_16.png "[Whamcloud Community Wiki] Page"){kind=icon}
Activity
Oleg Drokin (oleg.drokin@intel.com) merged in patch https://review.whamcloud.com/26059/
Subject: LU-9040 scrub: handle group boundary properly (2)
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 88c2664437b9110ee164aef176b1c126c23fdc1e
Fan Yong (fan.yong@intel.com) uploaded a new patch: https://review.whamcloud.com/26059
Subject: LU-9040 scrub: handle group boundary properly (2)
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 263986ad76bedf44db3d50f81104d9fad0fad1c3
We will be migrating the soak platform to RHEL 7.3 this month, we will reproduce with that build. A newer kernel may change the picture.
The new hung on MDT is different from the former one. The threads on the MDT hung at two places, one is at "lod_qos_prep_create+0xe12":
(gdb) l *lod_qos_prep_create+0xe12
0x2b232 is in lod_qos_prep_create (/root/Work/Lustre/L95/lustre-release/lustre/lod/lod_qos.c:279).
274 if (cfs_time_beforeq_64(max_age, obd->obd_osfs_age))
275 /* statfs data are quite recent, don't need to refresh it */
276 RETURN_EXIT;
277
278 down_write(&lod->lod_qos.lq_rw_sem);
279 if (cfs_time_beforeq_64(max_age, obd->obd_osfs_age))
280 goto out;
281
282 for (i = 0; i < osts->op_count; i++) {
283 idx = osts->op_array[i];
That means lod_qos_statfs_update() was blocked when "down_write(&lod->lod_qos.lq_rw_sem);". Because some other threads have taken such semaphore as read mode via lod_alloc_rr(). Unfortunately, these threads were blocked at "osp_precreate_reserve+0x406":
(gdb) l *osp_precreate_reserve+0x406
0x131d6 is in osp_precreate_reserve (/root/Work/Lustre/L95/lustre-release/lustre/osp/osp_precreate.c:1457).
1452 if (cfs_time_aftereq(cfs_time_current(), expire)) {
1453 rc = -ETIMEDOUT;
1454 break;
1455 }
1456
1457 l_wait_event(d->opd_pre_user_waitq,
1458 osp_precreate_ready_condition(env, d), &lwi);
1459 }
1460
That means the pre-create was blocked for some reason. I found lola-6 one of the OSS node fall into soft lockup, a lot of message like following:
BUG: soft lockup - CPU#20 stuck for 67s! [ldlm_cn00_013:21784] Modules linked in: osp(U) ofd(U) lfsck(U) ost(U) mgc(U) osd_zfs(U) lquota(U) lustre(U) lov(U) mdc(U) fid(U) lmv(U) fld(U) ko2iblnd(U) ptlrpc(U) obdclass(U) lnet(U) sha512_generic crc32c_intel libcfs(U) nfsd exportfs nfs lockd fscache auth_rpcgss nfs_acl sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm dm_round_robin dm_multipath microcode iTCO_wdt iTCO_vendor_support zfs(P)(U) raid1 zcommon(P)(U) znvpair(P)(U) spl(U) zlib_deflate zavl(P)(U) zunicode(P)(U) sb_edac edac_core lpc_ich mfd_core joydev i2c_i801 ioatdma ses enclosure sg igb dca i2c_algo_bit i2c_core ext3 jbd mbcache sd_mod crc_t10dif ahci wmi isci libsas mpt2sas scsi_transport_sas raid_class mlx4_ib ib_sa ib_mad ib_core ib_addr ipv6 mlx4_en ptp pps_core mlx4_core dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan] CPU 20 Modules linked in: osp(U) ofd(U) lfsck(U) ost(U) mgc(U) osd_zfs(U) lquota(U) lustre(U) lov(U) mdc(U) fid(U) lmv(U) fld(U) ko2iblnd(U) ptlrpc(U) obdclass(U) lnet(U) sha512_generic crc32c_intel libcfs(U) nfsd exportfs nfs lockd fscache auth_rpcgss nfs_acl sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ib_ipoib rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm dm_round_robin dm_multipath microcode iTCO_wdt iTCO_vendor_support zfs(P)(U) raid1 zcommon(P)(U) znvpair(P)(U) spl(U) zlib_deflate zavl(P)(U) zunicode(P)(U) sb_edac edac_core lpc_ich mfd_core joydev i2c_i801 ioatdma ses enclosure sg igb dca i2c_algo_bit i2c_core ext3 jbd mbcache sd_mod crc_t10dif ahci wmi isci libsas mpt2sas scsi_transport_sas raid_class mlx4_ib ib_sa ib_mad ib_core ib_addr ipv6 mlx4_en ptp pps_core mlx4_core dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan] Pid: 21784, comm: ldlm_cn00_013 Tainted: P --L------------ 2.6.32-573.26.1.el6_lustre.x86_64 #1 Intel Corporation S2600GZ ........../S2600GZ RIP: 0010:[<ffffffff8153cfe1>] [<ffffffff8153cfe1>] _spin_lock+0x21/0x30 RSP: 0018:ffff880206b4bab0 EFLAGS: 00000297 RAX: 0000000000009bbf RBX: ffff880206b4bab0 RCX: 0000000000000000 RDX: 0000000000009ba1 RSI: 0000000000000001 RDI: ffff8808341b5340 RBP: ffffffff8100bc0e R08: 0b90000000000000 R09: 5c80000000000000 R10: 0000000000000001 R11: 00000000ffffffff R12: 0000000006b4ba40 R13: ffff880000021dd8 R14: 0000000000000000 R15: 000000028f70ac00 FS: 0000000000000000(0000) GS:ffff880038780000(0000) knlGS:0000000000000000 CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b CR2: 00007fea1359c000 CR3: 00000004144ec000 CR4: 00000000000407e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 Process ldlm_cn00_013 (pid: 21784, threadinfo ffff880206b48000, task ffff880274004040) Stack: ffff880206b4baf0 ffffffffa081c7ab ffff8802cd94cb88 0000000000000000 <d> ffff880206b4baf0 ffff8804181ddc00 0000000000000000 ffff880835d0d6d8 <d> ffff880206b4bbd0 ffffffffa087f97f ffff880206b4bb70 0000000000000286 Call Trace: [<ffffffffa081c7ab>] ? cfs_percpt_lock+0x5b/0x110 [libcfs] [<ffffffffa087f97f>] ? lnet_send+0x65f/0x11d0 [lnet] [<ffffffff81149461>] ? kzfree+0x31/0x40 [<ffffffffa0882aef>] ? LNetPut+0x2ff/0x810 [lnet] [<ffffffffa0b39ff4>] ? ptl_send_buf+0x194/0x580 [ptlrpc] [<ffffffffa0b3a67d>] ? ptlrpc_send_reply+0x29d/0x840 [ptlrpc] [<ffffffffa0b4f43e>] ? ptlrpc_at_check_timed+0xd4e/0x1330 [ptlrpc] [<ffffffffa0b52c70>] ? ptlrpc_main+0xba0/0x18d0 [ptlrpc] [<ffffffffa0b520d0>] ? ptlrpc_main+0x0/0x18d0 [ptlrpc] [<ffffffff810a138e>] ? kthread+0x9e/0xc0 [<ffffffff8100c28a>] ? child_rip+0xa/0x20 [<ffffffff810a12f0>] ? kthread+0x0/0xc0 [<ffffffff8100c280>] ? child_rip+0x0/0x20 Code: 01 74 05 e8 e2 18 d6 ff c9 c3 55 48 89 e5 0f 1f 44 00 00 b8 00 00 01 00 f0 0f c1 07 0f b7 d0 c1 e8 10 39 c2 74 0e f3 90 0f b7 17 <eb> f5 83 3f 00 75 f4 eb df c9 c3 0f 1f 40 00 55 48 89 e5 0f 1f
It looks like LU-8334.
Oleg Drokin (oleg.drokin@intel.com) merged in patch https://review.whamcloud.com/25105/
Subject: LU-9040 scrub: handle group boundary properly
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 1e42682aeadb0f80dd6e9bfd45abe17221b698bf
The patch https://review.whamcloud.com/25370 may be not the perfected solution for the latest issue, but before we have more reasonable solution,we can use it in the new build. On the other hand, the original patch https://review.whamcloud.com/25105 is used for fixing different issue. So both should be used in the new build.
I believe lola-7 log (OST000b) was already uploaded - Should I try the latest patch?
Fan Yong (fan.yong@intel.com) uploaded a new patch: https://review.whamcloud.com/25370
Subject: LU-9040 ofd: keep orphan OST-objects conditionally
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 92f00817a67e941eb131d8ea86027a677cc2ec28
Fan Yong,
There are some recent sanity-sec test 9 hangs that have a very similar stack trace to the one in this ticket, but have the patch for this ticket. Would you please review these failures are determine if they are indeed the same issue as stated in this ticket or if they are new failures?
If the below logs show that these failures are unrelated to this ticket, then I can open a new one.
Here are a few of the recent failures:
2017-04-09 - https://testing.hpdd.intel.com/test_sets/1fb1e996-1d1c-11e7-8920-5254006e85c2
2017-04-11 - https://testing.hpdd.intel.com/test_sets/da448a92-1ef3-11e7-9de9-5254006e85c2
2017-04-12 - https://testing.hpdd.intel.com/test_sets/d251faa0-1fab-11e7-b742-5254006e85c2
2017-04-17 - https://testing.hpdd.intel.com/test_sets/4ddd019c-2362-11e7-8920-5254006e85c2