Uploaded image for project: 'Lustre'
  1. Lustre
  2. LU-13500

Client gets evicted - nfsd non-standard errorno -108

Details

    • Bug
    • Resolution: Unresolved
    • Minor
    • None
    • None
    • None
    • 3
    • 9223372036854775807

    Description

      Client is getting evicted by MDT as soon as nfsd service started on the client.

      client (golf1) kernel version : 3.10.0-1062.1.1.el7_lustre.x86_64
      client (golf1) lustre version : lustre-2.12.3-1.el7.x86_64

      mds (gmds1) kernel version : 3.10.0-1062.1.1.el7_lustre.x86_64
      mds (gmds1) lustre version : lustre-2.12.3-1.el7.x86_64

      oss (goss1-goss6) kernel version : 3.10.0-1062.1.1.el7_lustre.x86_64
      oss (goss1-goss6) lustre version : lustre-2.12.3-1.el7.x86_64

      /etc/exports on golf1 :

      /user_data       10.25.0.0/16(fsid=123456789,rw,anonuid=0,insecure,no_subtree_check,insecure_locks,async)
      
      Apr 30 14:03:07 golf1 kernel: LustreError: 11-0: golf-MDT0000-mdc-ffff973bf6409800: operation ldlm_enqueue to node 10.25.22.90@tcp failed: rc = -107
      Apr 30 14:03:07 golf1 kernel: Lustre: golf-MDT0000-mdc-ffff973bf6409800: Connection to golf-MDT0000 (at 10.25.22.90@tcp) was lost; in progress operations using this service will wait for recovery to complete
      Apr 30 14:03:07 golf1 kernel: LustreError: Skipped 8 previous similar messages
      Apr 30 14:03:07 golf1 kernel: LustreError: 167-0: golf-MDT0000-mdc-ffff973bf6409800: This client was evicted by golf-MDT0000; in progress operations using this service will fail.
      Apr 30 14:03:07 golf1 kernel: LustreError: 25491:0:(file.c:4339:ll_inode_revalidate_fini()) golf: revalidate FID [0x20004884e:0x16:0x0] error: rc = -5
      Apr 30 14:03:07 golf1 kernel: ------------[ cut here ]------------
      Apr 30 14:03:07 golf1 kernel: WARNING: CPU: 26 PID: 25600 at fs/nfsd/nfsproc.c:805 nfserrno+0x58/0x70 [nfsd]
      Apr 30 14:03:07 golf1 kernel: LustreError: 25579:0:(file.c:216:ll_close_inode_openhandle()) golf-clilmv-ffff973bf6409800: inode [0x20004884e:0x15:0x0] mdc close failed: rc = -108
      Apr 30 14:03:07 golf1 kernel: ------------[ cut here ]------------
      Apr 30 14:03:07 golf1 kernel: ------------[ cut here ]------------
      Apr 30 14:03:07 golf1 kernel: nfsd: non-standard errno: -108
      Apr 30 14:03:07 golf1 kernel: ------------[ cut here ]------------
      Apr 30 14:03:07 golf1 kernel: WARNING: CPU: 54 PID: 25602 at fs/nfsd/nfsproc.c:805 nfserrno+0x58/0x70 [nfsd]
      Apr 30 14:03:07 golf1 kernel: LustreError: 25579:0:(file.c:216:ll_close_inode_openhandle()) Skipped 2 previous similar messages
      Apr 30 14:03:07 golf1 kernel: WARNING: CPU: 24 PID: 25601 at fs/nfsd/nfsproc.c:805 nfserrno+0x58/0x70 [nfsd]
      Apr 30 14:03:07 golf1 kernel: WARNING: CPU: 9 PID: 25505 at fs/nfsd/nfsproc.c:805 nfserrno+0x58/0x70 [nfsd]
      

      Attachments

        1. hmds1-log-write.png
          hmds1-log-write.png
          7 kB
        2. hmds1-timezone.png
          hmds1-timezone.png
          22 kB
        3. hotel1-logs-write.png
          hotel1-logs-write.png
          9 kB
        4. hotel1-timezone.png
          hotel1-timezone.png
          22 kB
        5. vmcore-dmesg-2021-05-11.txt
          156 kB
        6. vmcore-dmesg-2021-06-17.txt
          150 kB

        Issue Links

          Activity

            [LU-13500] Client gets evicted - nfsd non-standard errorno -108

            I have uploaded the crash logs for couple of reboot instances to check this further.

            Uploaded file name: vmcore-dmesg-2021-06-17.txt - Restarted on 17th June
            vmcore-dmesg-2021-05-11.txt - Restarted on 11th May

            Last restart instance

            reboot   system boot  3.10.0-1062.18.1 Thu Jun 17 16:34 - 14:58 (7+22:23)
            

            Load usage seems to be normal during that time

            03:50:01 PM         2      1990      8.66      8.37      9.16         2
            04:00:01 PM        11      1981      6.24      8.02      8.75         1
            04:10:01 PM        15      1981      9.57     10.08      9.54         3
            04:20:01 PM         2      1982     11.88     13.18     11.28         1
            Average:           10      1983     10.40     10.50     10.42         2
            
            04:35:02 PM       LINUX RESTART
            
            04:40:01 PM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
            04:50:01 PM         2      1917     14.27     12.43      7.79         2
            05:00:01 PM         5      1939     13.30     13.36     10.71         3
            05:10:01 PM        11      1931     11.81     12.92     11.84         3
            05:20:01 PM        20      1924     17.28     14.74     13.02         2
            

            Most of the restart, could see the message "blk_update_request: critical medium error" always.

            [463108.636890] blk_update_request: critical medium error, dev nvme3n1, sector 5325696536
            [622470.873927] md: md0: data-check done.
            [955488.123023] md: data-check of RAID array md0
            [1028448.215074] ------------[ cut here ]------------
            [1028448.215083] WARNING: CPU: 7 PID: 0 at lib/percpu-refcount.c:155 percpu_ref_switch_to_atomic_rcu+0x136/0x150
            [1028448.215088] percpu ref (no_op) <= 0 (0) after switching to atomic
            [1028448.215089] Modules linked in:
            [1028448.215091]  vfat fat osp(OE) mdd(OE) lod(OE) mdt(OE) lfsck(OE) mgs(OE) mgc(OE) mpt3sas mpt2sas raid_class scsi_transport_sas mptctl mptbase osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) fid(OE) fld(OE) ksocklnd(OE) ptlrpc(OE) mbcache jbd2 obdclass(OE) lnet(OE) libcfs(OE) dell_rbu nfsv3 nfs fscache binfmt_misc bonding iTCO_wdt iTCO_vendor_support mxm_wmi dcdbas sb_edac intel_powerclamp coretemp intel_rapl iosf_mbi kvm_intel kvm irqbypass raid10 sg lpc_ich mei_me mei ipmi_si ipmi_devintf ipmi_msghandler wmi acpi_power_meter pcc_cpufreq nfsd auth_rpcgss nfs_acl lockd grace ip_tables xfs sd_mod crc_t10dif crct10dif_generic 8021q garp mrp stp llc mgag200 i2c_algo_bit drm_kms_helper bnx2x syscopyarea sysfillrect sysimgblt fb_sys_fops ttm crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel ghash_clmulni_intel
            [1028448.215136]  ahci drm aesni_intel lrw gf128mul libahci glue_helper ablk_helper cryptd scsi_transport_iscsi libata megaraid_sas nvme ptp nvme_core pps_core drm_panel_orientation_quirks mdio libcrc32c dm_multipath sunrpc dm_mirror dm_region_hash dm_log dm_mod [last unloaded: usb_storage]
            [1028448.215163] CPU: 7 PID: 0 Comm: swapper/7 Kdump: loaded Tainted: G           OE  ------------   3.10.0-1062.18.1.el7_lustre.x86_64 #1
            [1028448.215164] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.11.0 11/02/2019
            [1028448.215165] Call Trace:
            [1028448.215167]  <IRQ>  [<ffffffff8cf7b416>] dump_stack+0x19/0x1b
            [1028448.215178]  [<ffffffff8c89bab8>] __warn+0xd8/0x100
            [1028448.215180]  [<ffffffff8c89bb3f>] warn_slowpath_fmt+0x5f/0x80
            [1028448.215185]  [<ffffffff8c958b6d>] ? rcu_advance_cbs+0xcd/0xe0
            [1028448.215187]  [<ffffffff8cd9b740>] ? null_show+0x20/0x20
            [1028448.215189]  [<ffffffff8cb86cd6>] percpu_ref_switch_to_atomic_rcu+0x136/0x150
            [1028448.215192]  [<ffffffff8c95a4f8>] rcu_process_callbacks+0x1d8/0x570
            [1028448.215195]  [<ffffffff8c8a5435>] __do_softirq+0xf5/0x280
            [1028448.215200]  [<ffffffff8cf9242c>] call_softirq+0x1c/0x30
            [1028448.215204]  [<ffffffff8c82f715>] do_softirq+0x65/0xa0
            [1028448.215206]  [<ffffffff8c8a57b5>] irq_exit+0x105/0x110
            [1028448.215209]  [<ffffffff8cf939d8>] smp_apic_timer_interrupt+0x48/0x60
            [1028448.215211]  [<ffffffff8cf8fefa>] apic_timer_interrupt+0x16a/0x170
            [1028448.215213]  <EOI>  [<ffffffff8cdc2027>] ? cpuidle_enter_state+0x57/0xd0
            [1028448.215218]  [<ffffffff8cdc217e>] cpuidle_idle_call+0xde/0x230
            [1028448.215221]  [<ffffffff8c837c6e>] arch_cpu_idle+0xe/0xc0
            [1028448.215226]  [<ffffffff8c9017da>] cpu_startup_entry+0x14a/0x1e0
            [1028448.215231]  [<ffffffff8c85a0c7>] start_secondary+0x1f7/0x270
            [1028448.215234]  [<ffffffff8c8000d5>] start_cpu+0x5/0x14
            [1028448.215236] ---[ end trace 4441139b69972efc ]---
            [1136636.662352] blk_update_request: critical medium error, dev nvme3n1, sector 10406963584
            [1136636.710304] blk_update_request: critical medium error, dev nvme3n1, sector 10406967424
            [1165058.648561] md: md0: data-check done.
            [1560227.473353] md: data-check of RAID array md0
            [1745005.678257] blk_update_request: critical medium error, dev nvme3n1, sector 9927251728
            [1779948.753709] md: md0: data-check done.
            [1852184.120501] blk_update_request: critical medium error, dev nvme3n1, sector 9334756896
            [1852184.120532] md/raid10:md0: nvme3n1: rescheduling sector 18668989512
            [1852184.120644] blk_update_request: critical medium error, dev nvme3n1, sector 9334757280
            [1852184.120673] md/raid10:md0: nvme3n1: rescheduling sector 18668990280
            [1852184.120952] blk_update_request: critical medium error, dev nvme3n1, sector 9334756896
            [1852184.121138] md/raid10:md0: read error corrected (8 sectors at 262144 on nvme3n1)
            [1852184.121148] md/raid10:md0: nvme2n1: redirecting sector 18668989512 to another mirror
            [1852184.121526] blk_update_request: critical medium error, dev nvme3n1, sector 9334757280
            [1852184.121709] md/raid10:md0: read error corrected (8 sectors at 262144 on nvme3n1)
            [1852184.121720] md/raid10:md0: nvme2n1: redirecting sector 18668990280 to another mirror
            [2164966.710539] md: data-check of RAID array md0
            [2183165.845838] blk_update_request: critical medium error, dev nvme3n1, sector 917466240
            [2183165.846403] blk_update_request: critical medium error, dev nvme3n1, sector 917466280
            [2431150.697903] md: md0: data-check done.
            [2769705.550545] md: data-check of RAID array md0
            [2969839.376579] 
            
            sector 10812151448
            [2993948.791186] md: md0: data-check done.
            [3170956.989559] ------------[ cut here ]------------
            [3170956.989584] kernel BUG at /tmp/rpmbuild-lustre-jenkins-KWaNslf3/BUILD/lustre-2.12.5_62_gac40c31/ldiskfs/htree_lock.c:429!
            [3170956.989617] invalid opcode: 0000 [#1] SMP 
            [3170956.989634] Modules linked in: vfat fat osp(OE) mdd(OE) lod(OE) mdt(OE) lfsck(OE) mgs(OE) mgc(OE) mpt3sas mpt2sas raid_class scsi_transport_sas mptctl mptbase osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) fid(OE) fld(OE) ksocklnd(OE) ptlrpc(OE) mbcache jbd2 obdclass(OE) lnet(OE) libcfs(OE) dell_rbu nfsv3 nfs fscache binfmt_misc bonding iTCO_wdt iTCO_vendor_support mxm_wmi dcdbas sb_edac intel_powerclamp coretemp intel_rapl iosf_mbi kvm_intel kvm irqbypass raid10 sg lpc_ich mei_me mei ipmi_si ipmi_devintf ipmi_msghandler wmi acpi_power_meter pcc_cpufreq nfsd auth_rpcgss nfs_acl lockd grace ip_tables xfs sd_mod crc_t10dif crct10dif_generic 8021q garp mrp stp llc mgag200 i2c_algo_bit drm_kms_helper bnx2x syscopyarea sysfillrect sysimgblt fb_sys_fops ttm crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel
            [3170956.989935]  ghash_clmulni_intel ahci drm aesni_intel lrw gf128mul libahci glue_helper ablk_helper cryptd scsi_transport_iscsi libata megaraid_sas nvme ptp nvme_core pps_core drm_panel_orientation_quirks mdio libcrc32c dm_multipath sunrpc dm_mirror dm_region_hash dm_log dm_mod [last unloaded: usb_storage]
            [3170956.990047] CPU: 28 PID: 17088 Comm: mdt00_017 Kdump: loaded Tainted: G        W  OE  ------------   3.10.0-1062.18.1.el7_lustre.x86_64 #1
            [3170956.990085] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.11.0 11/02/2019
            [3170956.990109] task: ffff9de935f041c0 ti: ffff9de74522c000 task.ti: ffff9de74522c000
            [3170956.990132] RIP: 0010:[<ffffffffc0a86284>]  [<ffffffffc0a86284>] htree_node_unlock+0x4b4/0x4c0 [ldiskfs]
            [3170956.990179] RSP: 0018:ffff9de74522f8b0  EFLAGS: 00010246
            [3170956.990197] RAX: ffff9de933d98600 RBX: 0000000000000001 RCX: ffff9e0936a5b290
            [3170956.990219] RDX: 00000000000000c8 RSI: 0000000000000001 RDI: 0000000000000000
            [3170956.990241] RBP: ffff9de74522f928 R08: ffff9dcca9a01d00 R09: ffff9dda59559500
            [3170956.990263] R10: 0000000000000000 R11: ffff9dcd260b9258 R12: ffff9e0936a5b2d8
            [3170956.990285] R13: 0000000000000000 R14: ffff9de7ffea8a00 R15: ffff9dcd260b91e0
            [3170956.990308] FS:  0000000000000000(0000) GS:ffff9de93f980000(0000) knlGS:0000000000000000
            [3170956.990332] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
            [3170956.991222] CR2: 00007fdb46c25000 CR3: 0000003ff39b8000 CR4: 00000000003607e0
            [3170956.992087] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
            [3170956.992943] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
            [3170956.993790] Call Trace:
            [3170956.994639]  [<ffffffffc0a8646a>] htree_node_release_all+0x5a/0x80 [ldiskfs]
            [3170956.995505]  [<ffffffffc0a864b2>] htree_unlock+0x22/0x70 [ldiskfs]
            [3170956.996363]  [<ffffffffc0ad7b1e>] osd_index_ea_delete+0x30e/0xb10 [osd_ldiskfs]
            [3170956.997244]  [<ffffffffc138efa8>] lod_sub_delete+0x1c8/0x460 [lod]
            [3170956.998285]  [<ffffffffc1369c24>] lod_delete+0x24/0x30 [lod]
            [3170956.999350]  [<ffffffffc13de7c4>] __mdd_index_delete_only+0x194/0x250 [mdd]
            [3170957.000391]  [<ffffffffc13e1136>] __mdd_index_delete+0x46/0x290 [mdd]
            [3170957.001480]  [<ffffffffc13eee78>] mdd_unlink+0x5f8/0xaa0 [mdd]
            [3170957.002467]  [<ffffffffc12b0b69>] mdo_unlink+0x46/0x48 [mdt]
            [3170957.003319]  [<ffffffffc1274b1d>] mdt_reint_unlink+0xbed/0x14b0 [mdt]
            [3170957.004156]  [<ffffffffc12791b3>] mdt_reint_rec+0x83/0x210 [mdt]
            [3170957.004990]  [<ffffffffc1255383>] mdt_reint_internal+0x6e3/0xaf0 [mdt]
            [3170957.005829]  [<ffffffffc12610f7>] mdt_reint+0x67/0x140 [mdt]
            [3170957.006704]  [<ffffffffc0f86e8a>] tgt_request_handle+0xada/0x1570 [ptlrpc]
            [3170957.007724]  [<ffffffffc0f605d1>] ? ptlrpc_nrs_req_get_nolock0+0xd1/0x170 [ptlrpc]
            [3170957.008755]  [<ffffffffc082cbde>] ? ktime_get_real_seconds+0xe/0x10 [libcfs]
            [3170957.009747]  [<ffffffffc0f2b83b>] ptlrpc_server_handle_request+0x24b/0xab0 [ptlrpc]
            [3170957.010752]  [<ffffffffc0f28655>] ? ptlrpc_wait_event+0xa5/0x360 [ptlrpc]
            [3170957.011741]  [<ffffffff8c8d3a33>] ? __wake_up+0x13/0x20
            [3170957.012740]  [<ffffffffc0f2f1a4>] ptlrpc_main+0xb34/0x1470 [ptlrpc]
            [3170957.013630]  [<ffffffffc0f2e670>] ? ptlrpc_register_service+0xf80/0xf80 [ptlrpc]
            [3170957.014404]  [<ffffffff8c8c6321>] kthread+0xd1/0xe0
            [3170957.015169]  [<ffffffff8c8c6250>] ? insert_kthread_work+0x40/0x40
            [3170957.015910]  [<ffffffff8cf8ed37>] ret_from_fork_nospec_begin+0x21/0x21
            [3170957.016633]  [<ffffffff8c8c6250>] ? insert_kthread_work+0x40/0x40
            [3170957.017336] Code: 0f 0b 48 8b 45 90 8b 55 8c f3 90 0f a3 10 19 c9 85 c9 75 f5 f0 0f ab 10 19 c9 85 c9 0f 84 a4 fb ff ff eb e5 0f 1f 00 0f 0b 0f 0b <0f> 0b 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 89 f0 48 
            [3170957.018817] RIP  [<ffffffffc0a86284>] htree_node_unlock+0x4b4/0x4c0 [ldiskfs]
            [3170957.019524]  RSP <ffff9de74522f8b0>
            
            cmcl Campbell Mcleay (Inactive) added a comment - - edited I have uploaded the crash logs for couple of reboot instances to check this further. Uploaded file name: vmcore-dmesg-2021-06-17.txt - Restarted on 17th June vmcore-dmesg-2021-05-11.txt - Restarted on 11th May Last restart instance reboot system boot 3.10.0-1062.18.1 Thu Jun 17 16:34 - 14:58 (7+22:23) Load usage seems to be normal during that time 03:50:01 PM 2 1990 8.66 8.37 9.16 2 04:00:01 PM 11 1981 6.24 8.02 8.75 1 04:10:01 PM 15 1981 9.57 10.08 9.54 3 04:20:01 PM 2 1982 11.88 13.18 11.28 1 Average: 10 1983 10.40 10.50 10.42 2 04:35:02 PM LINUX RESTART 04:40:01 PM runq-sz plist-sz ldavg-1 ldavg-5 ldavg-15 blocked 04:50:01 PM 2 1917 14.27 12.43 7.79 2 05:00:01 PM 5 1939 13.30 13.36 10.71 3 05:10:01 PM 11 1931 11.81 12.92 11.84 3 05:20:01 PM 20 1924 17.28 14.74 13.02 2 Most of the restart, could see the message "blk_update_request: critical medium error" always. [463108.636890] blk_update_request: critical medium error, dev nvme3n1, sector 5325696536 [622470.873927] md: md0: data-check done. [955488.123023] md: data-check of RAID array md0 [1028448.215074] ------------[ cut here ]------------ [1028448.215083] WARNING: CPU: 7 PID: 0 at lib/percpu-refcount.c:155 percpu_ref_switch_to_atomic_rcu+0x136/0x150 [1028448.215088] percpu ref (no_op) <= 0 (0) after switching to atomic [1028448.215089] Modules linked in: [1028448.215091] vfat fat osp(OE) mdd(OE) lod(OE) mdt(OE) lfsck(OE) mgs(OE) mgc(OE) mpt3sas mpt2sas raid_class scsi_transport_sas mptctl mptbase osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) fid(OE) fld(OE) ksocklnd(OE) ptlrpc(OE) mbcache jbd2 obdclass(OE) lnet(OE) libcfs(OE) dell_rbu nfsv3 nfs fscache binfmt_misc bonding iTCO_wdt iTCO_vendor_support mxm_wmi dcdbas sb_edac intel_powerclamp coretemp intel_rapl iosf_mbi kvm_intel kvm irqbypass raid10 sg lpc_ich mei_me mei ipmi_si ipmi_devintf ipmi_msghandler wmi acpi_power_meter pcc_cpufreq nfsd auth_rpcgss nfs_acl lockd grace ip_tables xfs sd_mod crc_t10dif crct10dif_generic 8021q garp mrp stp llc mgag200 i2c_algo_bit drm_kms_helper bnx2x syscopyarea sysfillrect sysimgblt fb_sys_fops ttm crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel ghash_clmulni_intel [1028448.215136] ahci drm aesni_intel lrw gf128mul libahci glue_helper ablk_helper cryptd scsi_transport_iscsi libata megaraid_sas nvme ptp nvme_core pps_core drm_panel_orientation_quirks mdio libcrc32c dm_multipath sunrpc dm_mirror dm_region_hash dm_log dm_mod [last unloaded: usb_storage] [1028448.215163] CPU: 7 PID: 0 Comm: swapper/7 Kdump: loaded Tainted: G OE ------------ 3.10.0-1062.18.1.el7_lustre.x86_64 #1 [1028448.215164] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.11.0 11/02/2019 [1028448.215165] Call Trace: [1028448.215167] <IRQ> [<ffffffff8cf7b416>] dump_stack+0x19/0x1b [1028448.215178] [<ffffffff8c89bab8>] __warn+0xd8/0x100 [1028448.215180] [<ffffffff8c89bb3f>] warn_slowpath_fmt+0x5f/0x80 [1028448.215185] [<ffffffff8c958b6d>] ? rcu_advance_cbs+0xcd/0xe0 [1028448.215187] [<ffffffff8cd9b740>] ? null_show+0x20/0x20 [1028448.215189] [<ffffffff8cb86cd6>] percpu_ref_switch_to_atomic_rcu+0x136/0x150 [1028448.215192] [<ffffffff8c95a4f8>] rcu_process_callbacks+0x1d8/0x570 [1028448.215195] [<ffffffff8c8a5435>] __do_softirq+0xf5/0x280 [1028448.215200] [<ffffffff8cf9242c>] call_softirq+0x1c/0x30 [1028448.215204] [<ffffffff8c82f715>] do_softirq+0x65/0xa0 [1028448.215206] [<ffffffff8c8a57b5>] irq_exit+0x105/0x110 [1028448.215209] [<ffffffff8cf939d8>] smp_apic_timer_interrupt+0x48/0x60 [1028448.215211] [<ffffffff8cf8fefa>] apic_timer_interrupt+0x16a/0x170 [1028448.215213] <EOI> [<ffffffff8cdc2027>] ? cpuidle_enter_state+0x57/0xd0 [1028448.215218] [<ffffffff8cdc217e>] cpuidle_idle_call+0xde/0x230 [1028448.215221] [<ffffffff8c837c6e>] arch_cpu_idle+0xe/0xc0 [1028448.215226] [<ffffffff8c9017da>] cpu_startup_entry+0x14a/0x1e0 [1028448.215231] [<ffffffff8c85a0c7>] start_secondary+0x1f7/0x270 [1028448.215234] [<ffffffff8c8000d5>] start_cpu+0x5/0x14 [1028448.215236] ---[ end trace 4441139b69972efc ]--- [1136636.662352] blk_update_request: critical medium error, dev nvme3n1, sector 10406963584 [1136636.710304] blk_update_request: critical medium error, dev nvme3n1, sector 10406967424 [1165058.648561] md: md0: data-check done. [1560227.473353] md: data-check of RAID array md0 [1745005.678257] blk_update_request: critical medium error, dev nvme3n1, sector 9927251728 [1779948.753709] md: md0: data-check done. [1852184.120501] blk_update_request: critical medium error, dev nvme3n1, sector 9334756896 [1852184.120532] md/raid10:md0: nvme3n1: rescheduling sector 18668989512 [1852184.120644] blk_update_request: critical medium error, dev nvme3n1, sector 9334757280 [1852184.120673] md/raid10:md0: nvme3n1: rescheduling sector 18668990280 [1852184.120952] blk_update_request: critical medium error, dev nvme3n1, sector 9334756896 [1852184.121138] md/raid10:md0: read error corrected (8 sectors at 262144 on nvme3n1) [1852184.121148] md/raid10:md0: nvme2n1: redirecting sector 18668989512 to another mirror [1852184.121526] blk_update_request: critical medium error, dev nvme3n1, sector 9334757280 [1852184.121709] md/raid10:md0: read error corrected (8 sectors at 262144 on nvme3n1) [1852184.121720] md/raid10:md0: nvme2n1: redirecting sector 18668990280 to another mirror [2164966.710539] md: data-check of RAID array md0 [2183165.845838] blk_update_request: critical medium error, dev nvme3n1, sector 917466240 [2183165.846403] blk_update_request: critical medium error, dev nvme3n1, sector 917466280 [2431150.697903] md: md0: data-check done. [2769705.550545] md: data-check of RAID array md0 [2969839.376579] sector 10812151448 [2993948.791186] md: md0: data-check done. [3170956.989559] ------------[ cut here ]------------ [3170956.989584] kernel BUG at /tmp/rpmbuild-lustre-jenkins-KWaNslf3/BUILD/lustre-2.12.5_62_gac40c31/ldiskfs/htree_lock.c:429! [3170956.989617] invalid opcode: 0000 [#1] SMP [3170956.989634] Modules linked in: vfat fat osp(OE) mdd(OE) lod(OE) mdt(OE) lfsck(OE) mgs(OE) mgc(OE) mpt3sas mpt2sas raid_class scsi_transport_sas mptctl mptbase osd_ldiskfs(OE) ldiskfs(OE) lquota(OE) fid(OE) fld(OE) ksocklnd(OE) ptlrpc(OE) mbcache jbd2 obdclass(OE) lnet(OE) libcfs(OE) dell_rbu nfsv3 nfs fscache binfmt_misc bonding iTCO_wdt iTCO_vendor_support mxm_wmi dcdbas sb_edac intel_powerclamp coretemp intel_rapl iosf_mbi kvm_intel kvm irqbypass raid10 sg lpc_ich mei_me mei ipmi_si ipmi_devintf ipmi_msghandler wmi acpi_power_meter pcc_cpufreq nfsd auth_rpcgss nfs_acl lockd grace ip_tables xfs sd_mod crc_t10dif crct10dif_generic 8021q garp mrp stp llc mgag200 i2c_algo_bit drm_kms_helper bnx2x syscopyarea sysfillrect sysimgblt fb_sys_fops ttm crct10dif_pclmul crct10dif_common crc32_pclmul crc32c_intel [3170956.989935] ghash_clmulni_intel ahci drm aesni_intel lrw gf128mul libahci glue_helper ablk_helper cryptd scsi_transport_iscsi libata megaraid_sas nvme ptp nvme_core pps_core drm_panel_orientation_quirks mdio libcrc32c dm_multipath sunrpc dm_mirror dm_region_hash dm_log dm_mod [last unloaded: usb_storage] [3170956.990047] CPU: 28 PID: 17088 Comm: mdt00_017 Kdump: loaded Tainted: G W OE ------------ 3.10.0-1062.18.1.el7_lustre.x86_64 #1 [3170956.990085] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.11.0 11/02/2019 [3170956.990109] task: ffff9de935f041c0 ti: ffff9de74522c000 task.ti: ffff9de74522c000 [3170956.990132] RIP: 0010:[<ffffffffc0a86284>] [<ffffffffc0a86284>] htree_node_unlock+0x4b4/0x4c0 [ldiskfs] [3170956.990179] RSP: 0018:ffff9de74522f8b0 EFLAGS: 00010246 [3170956.990197] RAX: ffff9de933d98600 RBX: 0000000000000001 RCX: ffff9e0936a5b290 [3170956.990219] RDX: 00000000000000c8 RSI: 0000000000000001 RDI: 0000000000000000 [3170956.990241] RBP: ffff9de74522f928 R08: ffff9dcca9a01d00 R09: ffff9dda59559500 [3170956.990263] R10: 0000000000000000 R11: ffff9dcd260b9258 R12: ffff9e0936a5b2d8 [3170956.990285] R13: 0000000000000000 R14: ffff9de7ffea8a00 R15: ffff9dcd260b91e0 [3170956.990308] FS: 0000000000000000(0000) GS:ffff9de93f980000(0000) knlGS:0000000000000000 [3170956.990332] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [3170956.991222] CR2: 00007fdb46c25000 CR3: 0000003ff39b8000 CR4: 00000000003607e0 [3170956.992087] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [3170956.992943] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [3170956.993790] Call Trace: [3170956.994639] [<ffffffffc0a8646a>] htree_node_release_all+0x5a/0x80 [ldiskfs] [3170956.995505] [<ffffffffc0a864b2>] htree_unlock+0x22/0x70 [ldiskfs] [3170956.996363] [<ffffffffc0ad7b1e>] osd_index_ea_delete+0x30e/0xb10 [osd_ldiskfs] [3170956.997244] [<ffffffffc138efa8>] lod_sub_delete+0x1c8/0x460 [lod] [3170956.998285] [<ffffffffc1369c24>] lod_delete+0x24/0x30 [lod] [3170956.999350] [<ffffffffc13de7c4>] __mdd_index_delete_only+0x194/0x250 [mdd] [3170957.000391] [<ffffffffc13e1136>] __mdd_index_delete+0x46/0x290 [mdd] [3170957.001480] [<ffffffffc13eee78>] mdd_unlink+0x5f8/0xaa0 [mdd] [3170957.002467] [<ffffffffc12b0b69>] mdo_unlink+0x46/0x48 [mdt] [3170957.003319] [<ffffffffc1274b1d>] mdt_reint_unlink+0xbed/0x14b0 [mdt] [3170957.004156] [<ffffffffc12791b3>] mdt_reint_rec+0x83/0x210 [mdt] [3170957.004990] [<ffffffffc1255383>] mdt_reint_internal+0x6e3/0xaf0 [mdt] [3170957.005829] [<ffffffffc12610f7>] mdt_reint+0x67/0x140 [mdt] [3170957.006704] [<ffffffffc0f86e8a>] tgt_request_handle+0xada/0x1570 [ptlrpc] [3170957.007724] [<ffffffffc0f605d1>] ? ptlrpc_nrs_req_get_nolock0+0xd1/0x170 [ptlrpc] [3170957.008755] [<ffffffffc082cbde>] ? ktime_get_real_seconds+0xe/0x10 [libcfs] [3170957.009747] [<ffffffffc0f2b83b>] ptlrpc_server_handle_request+0x24b/0xab0 [ptlrpc] [3170957.010752] [<ffffffffc0f28655>] ? ptlrpc_wait_event+0xa5/0x360 [ptlrpc] [3170957.011741] [<ffffffff8c8d3a33>] ? __wake_up+0x13/0x20 [3170957.012740] [<ffffffffc0f2f1a4>] ptlrpc_main+0xb34/0x1470 [ptlrpc] [3170957.013630] [<ffffffffc0f2e670>] ? ptlrpc_register_service+0xf80/0xf80 [ptlrpc] [3170957.014404] [<ffffffff8c8c6321>] kthread+0xd1/0xe0 [3170957.015169] [<ffffffff8c8c6250>] ? insert_kthread_work+0x40/0x40 [3170957.015910] [<ffffffff8cf8ed37>] ret_from_fork_nospec_begin+0x21/0x21 [3170957.016633] [<ffffffff8c8c6250>] ? insert_kthread_work+0x40/0x40 [3170957.017336] Code: 0f 0b 48 8b 45 90 8b 55 8c f3 90 0f a3 10 19 c9 85 c9 75 f5 f0 0f ab 10 19 c9 85 c9 0f 84 a4 fb ff ff eb e5 0f 1f 00 0f 0b 0f 0b <0f> 0b 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 89 f0 48 [3170957.018817] RIP [<ffffffffc0a86284>] htree_node_unlock+0x4b4/0x4c0 [ldiskfs] [3170957.019524] RSP <ffff9de74522f8b0>
            green Oleg Drokin added a comment -

            is there any more information about the MDS crashes/reboots? Is there an oops/lbug/assert (what's the stacktrace)? a HA-induced reboot due to high load/whatever? something else?

            green Oleg Drokin added a comment - is there any more information about the MDS crashes/reboots? Is there an oops/lbug/assert (what's the stacktrace)? a HA-induced reboot due to high load/whatever? something else?

            Hi Oleg Drokin,

            As we monitored the system with below suggested change , it's noticed that the Metadata server (hmds1) is getting rebooted randomly and the both the clients are evicting from the cluster which is again making issues. Could you please look into that more and suggest ?

            lctl set_param ldlm.namespaces.*MDT*mdc*.lru_size=100
            lctl set_param -P ldlm.namespaces.*.lru_size=10000
            lctl set_param -P ldlm.namespaces.*.lru_max_age=600000
            
            cmcl Campbell Mcleay (Inactive) added a comment - Hi Oleg Drokin, As we monitored the system with below suggested change , it's noticed that the Metadata server (hmds1) is getting rebooted randomly and the both the clients are evicting from the cluster which is again making issues. Could you please look into that more and suggest ? lctl set_param ldlm.namespaces.*MDT*mdc*.lru_size=100 lctl set_param -P ldlm.namespaces.*.lru_size=10000 lctl set_param -P ldlm.namespaces.*.lru_max_age=600000
            green Oleg Drokin added a comment -

            these ldlm settings look fine to me if they work for you. You can shorten the max age if you want depending on your workload.

            I can't comment on the "svc_rpc_per_connection_limit" parameter as I am not familiar with that part of the NFS stack.

            green Oleg Drokin added a comment - these ldlm settings look fine to me if they work for you. You can shorten the max age if you want depending on your workload. I can't comment on the "svc_rpc_per_connection_limit" parameter as I am not familiar with that part of the NFS stack.

            Any updates here ?

            cmcl Campbell Mcleay (Inactive) added a comment - Any updates here ?

            HI Oleg,

            We have modified the config for limit the number of nfsd threads a single client can use on NFS gateways which helped to avoid the further client evictions. We are not seeing any stack traces and the backups are running smoothly so far. 

            /sys/module/sunrpc/parameters/svc_rpc_per_connection_limit = 1
            

            Also we are having the below lru size configs are in place too on the clients

            lctl set_param -P ldlm.namespaces.*.lru_size=10000
            lctl set_param -P ldlm.namespaces.*.lru_max_age=600000
            

            Please check and suggest .

            cmcl Campbell Mcleay (Inactive) added a comment - HI Oleg, We have modified the config for limit the number of nfsd threads a single client can use on NFS gateways which helped to avoid the further client evictions. We are not seeing any stack traces and the backups are running smoothly so far.  /sys/module/sunrpc/parameters/svc_rpc_per_connection_limit = 1 Also we are having the below lru size configs are in place too on the clients lctl set_param -P ldlm.namespaces.*.lru_size=10000 lctl set_param -P ldlm.namespaces.*.lru_max_age=600000 Please check and suggest .

            Hi Oleg,

            Just some feedback on this setting: since the change has been made, there have been no stack traces, and the backups that run on that node have not been finishing early (so far). We'll see what happens when they finish, but looking much better so far!

            Thanks,

            Campbell

            cmcl Campbell Mcleay (Inactive) added a comment - Hi Oleg, Just some feedback on this setting: since the change has been made, there have been no stack traces, and the backups that run on that node have not been finishing early (so far). We'll see what happens when they finish, but looking much better so far! Thanks, Campbell
            green Oleg Drokin added a comment -

            So I wonder if reducing amount of mdt locks would at least help you temporarily since the problem is clearly related to parallel cancels.

            lctl set_param ldlm.namespaces.*MDT*mdc*.lru_size=100
            

            can you please run this on your nfs export node(s)? The setting is not permanent and would reset on node reboot/lustre client remount.

            green Oleg Drokin added a comment - So I wonder if reducing amount of mdt locks would at least help you temporarily since the problem is clearly related to parallel cancels. lctl set_param ldlm.namespaces.*MDT*mdc*.lru_size=100 can you please run this on your nfs export node(s)? The setting is not permanent and would reset on node reboot/lustre client remount.
            green Oleg Drokin added a comment -

            Sorry that I have no immediate answers to this, I am still thinking about the whole thing.

            green Oleg Drokin added a comment - Sorry that I have no immediate answers to this, I am still thinking about the whole thing.

            Hello Team,

            It would be really good if you can provide a solution for the same at the earliest as this is really affecting the production backup which is really putting us in a panic situations. Requesting you to check this on priority please. 

            cmcl Campbell Mcleay (Inactive) added a comment - Hello Team, It would be really good if you can provide a solution for the same at the earliest as this is really affecting the production backup which is really putting us in a panic situations. Requesting you to check this on priority please. 

            Any findings here please ?

            cmcl Campbell Mcleay (Inactive) added a comment - Any findings here please ?

            People

              green Oleg Drokin
              cmcl Campbell Mcleay (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

                Created:
                Updated: