Project

General

Profile

Actions

Bug #57703

closed

Bug #61200: ceph: corrupt snap message from mds1

Bug #57686: general protection fault and CephFS kernel client hangs after MDS failover

unable to handle page fault for address and system lockup after MDS failover

Added by Andreas Teuchert over 1 year ago. Updated over 1 year ago.

Status:
Duplicate
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

We have a four-node Ceph cluster (Ceph 17.2.1, Ubuntu 20.04, kernel 5.15.0-48-generic #54~20.04.1-Ubuntu), managed by cephadm that contains two CephFSs. On those nodes, two directories from one FS are mounted via the kernel client. There are eight active MDSs and four standby MDSs for the FS.

When an active MDS is failed, sometimes the following is logged on the console and the node locks up:

[ 2477.185311] ceph: update_snap_trace error -5
[ 2477.185675] ceph: update_snap_trace error -5
[ 2532.131282] ceph: update_snap_trace error -5
[ 2568.319964] ceph: update_snap_trace error -5
[ 2656.376007] ceph: update_snap_trace error -5
[ 2680.376103] ceph: update_snap_trace error -5
[ 2703.541210] ceph: update_snap_trace error -5
[ 2786.388598] ceph: update_snap_trace error -5
[ 2837.745228] ================================================================================
[ 2837.753771] UBSAN: array-index-out-of-bounds in /build/linux-hwe-5.15-XJ9mgb/linux-hwe-5.15-5.15.0/kernel/locking/qspinlock.c:130:9
[ 2837.765662] index 13703 is out of range for type 'long unsigned int [8192]'
[ 2837.772900] ================================================================================
[ 2837.781433] BUG: unable to handle page fault for address: 0000000000031920
[ 2837.788339] #PF: supervisor write access in kernel mode
[ 2837.793595] #PF: error_code(0x0002) - not-present page
[ 2837.798758] PGD 0 P4D 0 
[ 2837.801312] Oops: 0002 [#1] SMP NOPTI
[ 2837.804990] CPU: 18 PID: 16249 Comm: kworker/18:7 Not tainted 5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2837.813968] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2837.821467] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2837.826995] RIP: 0010:native_queued_spin_lock_slowpath+0x1d3/0x230
[ 2837.833198] Code: 83 e0 03 44 8d 71 ff 44 0f b7 e8 49 c1 e5 05 4d 63 f6 49 81 c5 00 19 03 00 49 81 fe ff 1f 00 00 77 49 4e 03 2c f5 e0 5a 8f ad <4d> 89 65 00 41 8b 44 24 08 85 c0 75 0b f3 90 41 8b 44 24 08 85 c0
[ 2837.852000] RSP: 0000:ffffb0fd8aba3b18 EFLAGS: 00010202
[ 2837.856307] ceph: update_snap_trace error -5
[ 2837.857246] RAX: ffff909f13a3c000 RBX: ffff909eb1e6e8d0 RCX: 0000000000000000
[ 2837.868702] RDX: 00000000004c0000 RSI: ffff90fb810a0580 RDI: ffff90fb810a0580
[ 2837.875859] RBP: ffffb0fd8aba3b40 R08: ffff90fb810a0580 R09: 0000000000000001
[ 2837.883013] R10: ffff909dcd10d380 R11: 0000000000000001 R12: ffff90fb810b1900
[ 2837.890170] R13: 0000000000031920 R14: 0000000000003587 R15: ffff909dd197e000
[ 2837.896497] ceph: update_snap_trace error -5
[ 2837.897328] FS:  0000000000000000(0000) GS:ffff90fb81080000(0000) knlGS:0000000000000000
[ 2837.897332] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2837.897333] CR2: 0000000000031920 CR3: 00000001f68a0005 CR4: 00000000007706e0
[ 2837.897335] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2837.897336] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2837.897337] PKRU: 55555554
[ 2837.897338] Call Trace:
[ 2837.897339]  <TASK>
[ 2837.897342]  _raw_spin_lock+0x22/0x30
[ 2837.897351]  ceph_change_snap_realm+0x3f/0x100 [ceph]
[ 2837.953066]  ceph_add_cap+0x32a/0x4b0 [ceph]
[ 2837.957380]  ceph_handle_caps+0x897/0xe80 [ceph]
[ 2837.962041]  mds_dispatch+0x11f/0x320 [ceph]
[ 2837.966363]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2837.971811]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2837.977923]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2837.983760]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2837.989244]  process_one_work+0x228/0x3d0
[ 2837.993843]  worker_thread+0x4d/0x3f0
[ 2837.998304]  ? process_one_work+0x3d0/0x3d0
[ 2838.003281]  kthread+0x127/0x150
[ 2838.007310]  ? set_kthread_struct+0x50/0x50
[ 2838.012291]  ret_from_fork+0x1f/0x30
[ 2838.016673]  </TASK>
[ 2838.019642] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2838.019720]  async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2838.139549] CR2: 0000000000031920
[ 2838.143785] ---[ end trace 83ffa01d1ff3ed2c ]---
[ 2838.202516] RIP: 0010:native_queued_spin_lock_slowpath+0x1d3/0x230
[ 2838.209621] Code: 83 e0 03 44 8d 71 ff 44 0f b7 e8 49 c1 e5 05 4d 63 f6 49 81 c5 00 19 03 00 49 81 fe ff 1f 00 00 77 49 4e 03 2c f5 e0 5a 8f ad <4d> 89 65 00 41 8b 44 24 08 85 c0 75 0b f3 90 41 8b 44 24 08 85 c0
[ 2838.230211] RSP: 0000:ffffb0fd8aba3b18 EFLAGS: 00010202
[ 2838.236359] RAX: ffff909f13a3c000 RBX: ffff909eb1e6e8d0 RCX: 0000000000000000
[ 2838.244413] RDX: 00000000004c0000 RSI: ffff90fb810a0580 RDI: ffff90fb810a0580
[ 2838.252479] RBP: ffffb0fd8aba3b40 R08: ffff90fb810a0580 R09: 0000000000000001
[ 2838.260539] R10: ffff909dcd10d380 R11: 0000000000000001 R12: ffff90fb810b1900
[ 2838.268556] R13: 0000000000031920 R14: 0000000000003587 R15: ffff909dd197e000
[ 2838.276377] FS:  0000000000000000(0000) GS:ffff90fb81080000(0000) knlGS:0000000000000000
[ 2838.285170] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2838.291609] CR2: 0000000000031920 CR3: 00000001f68a0005 CR4: 00000000007706e0
[ 2838.299436] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2838.307251] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2838.315068] PKRU: 55555554
[ 2838.701927] ceph: mds2 recovery completed
[ 2838.706732] ceph: mds7 recovery completed
[ 2844.907024] ------------[ cut here ]------------
[ 2844.912350] NETDEV WATCHDOG: transfer2 (i40e): transmit queue 9 timed out
[ 2844.919851] WARNING: CPU: 22 PID: 0 at net/sched/sch_generic.c:477 dev_watchdog+0x27a/0x290
[ 2844.928927] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2844.928991]  async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2845.048395] CPU: 22 PID: 0 Comm: swapper/22 Tainted: G      D           5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2845.059185] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2845.067607] RIP: 0010:dev_watchdog+0x27a/0x290
[ 2845.072991] Code: eb 97 48 8b 5d d0 c6 05 e0 50 6c 01 01 48 89 df e8 fb 79 f9 ff 44 89 e1 48 89 de 48 c7 c7 18 d3 8d ad 48 89 c2 e8 87 50 19 00 <0f> 0b eb 80 e9 42 8f 22 00 66 66 2e 0f 1f 84 00 00 00 00 00 66 90
[ 2845.093648] RSP: 0018:ffffb0fd80a24e80 EFLAGS: 00010282
[ 2845.099882] RAX: 0000000000000000 RBX: ffff909dd4e60000 RCX: 0000000000000000
[ 2845.107960] RDX: ffff90fb811ac240 RSI: ffff90fb811a0580 RDI: ffff90fb811a0580
[ 2845.116046] RBP: ffffb0fd80a24eb8 R08: ffff90fb811a0580 R09: 0000000000000001
[ 2845.124119] R10: ffff909dcd10dd30 R11: 0000000000000001 R12: 0000000000000009
[ 2845.132112] R13: ffff909dd9ea6740 R14: 0000000000000020 R15: ffff909dd4e604c0
[ 2845.140086] FS:  0000000000000000(0000) GS:ffff90fb81180000(0000) knlGS:0000000000000000
[ 2845.149013] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2845.155629] CR2: 0000559450fbf080 CR3: 00000001f023c005 CR4: 00000000007706e0
[ 2845.163657] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2845.171602] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2845.179543] PKRU: 55555554
[ 2845.183062] Call Trace:
[ 2845.186281]  <IRQ>
[ 2845.189057]  ? pfifo_fast_enqueue+0x160/0x160
[ 2845.194171]  call_timer_fn+0x2c/0x120
[ 2845.198577]  run_timer_softirq+0x433/0x4c0
[ 2845.203423]  ? lapic_next_deadline+0x2c/0x40
[ 2845.208447]  ? clockevents_program_event+0xa8/0x130
[ 2845.214068]  __do_softirq+0xda/0x2ee
[ 2845.218384]  irq_exit_rcu+0x7d/0xa0
[ 2845.222570]  sysvec_apic_timer_interrupt+0x80/0x90
[ 2845.228084]  </IRQ>
[ 2845.230851]  <TASK>
[ 2845.233656]  asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 2845.239524] RIP: 0010:cpuidle_enter_state+0xd9/0x620
[ 2845.245212] Code: 3d a4 e2 3c 53 e8 c7 d4 6b ff 49 89 c7 0f 1f 44 00 00 31 ff e8 78 e1 6b ff 80 7d d0 00 0f 85 5e 01 00 00 fb 66 0f 1f 44 00 00 <45> 85 f6 0f 88 6a 01 00 00 4d 63 ee 49 83 fd 09 0f 87 0c 04 00 00
[ 2845.265518] RSP: 0018:ffffb0fd802a3e18 EFLAGS: 00000246
[ 2845.271513] RAX: ffff90fb811b0b80 RBX: ffffd0fd7fd84a00 RCX: 0000000000000000
[ 2845.279427] RDX: 00000000004e50ed RSI: 000000003a2e8d5e RDI: 0000000000000000
[ 2845.287518] RBP: ffffb0fd802a3e68 R08: 0000029661ac17f5 R09: 000000000000ea60
[ 2845.295411] R10: 000000000000154e R11: 0000000000000004 R12: ffffffffae2d2ec0
[ 2845.303274] R13: 0000000000000001 R14: 0000000000000001 R15: 0000029661ac17f5
[ 2845.311118]  ? cpuidle_enter_state+0xc8/0x620
[ 2845.316172]  cpuidle_enter+0x2e/0x50
[ 2845.320425]  call_cpuidle+0x23/0x50
[ 2845.324574]  do_idle+0x1f4/0x270
[ 2845.328438]  cpu_startup_entry+0x20/0x30
[ 2845.332991]  start_secondary+0x12a/0x180
[ 2845.337541]  secondary_startup_64_no_verify+0xc2/0xcb
[ 2845.343195]  </TASK>
[ 2845.346221] ---[ end trace 83ffa01d1ff3ed2d ]---
[ 2845.351420] i40e 0000:b3:00.1 transfer2: tx_timeout: VSI_seid: 391, Q 9, NTC: 0x157, HWB: 0x16e, NTU: 0x171, TAIL: 0x171, INT: 0x0
[ 2845.364277] i40e 0000:b3:00.1 transfer2: tx_timeout recovery level 1, txqueue 9
[ 2845.931032] i40e 0000:b4:00.1 transfer3: tx_timeout: VSI_seid: 391, Q 14, NTC: 0x35, HWB: 0x1c, NTU: 0x1f, TAIL: 0x1f, INT: 0x0
[ 2845.943688] i40e 0000:b4:00.1 transfer3: tx_timeout recovery level 1, txqueue 14
[ 2847.979042] i40e 0000:b4:00.0 transfer1: tx_timeout: VSI_seid: 390, Q 9, NTC: 0x16f, HWB: 0x30, NTU: 0x33, TAIL: 0x33, INT: 0x0
[ 2847.991728] i40e 0000:b4:00.0 transfer1: tx_timeout recovery level 1, txqueue 9
[ 2850.795054] i40e 0000:b3:00.0 transfer0: tx_timeout: VSI_seid: 390, Q 8, NTC: 0x1ac, HWB: 0x196, NTU: 0x196, TAIL: 0x196, INT: 0x0
[ 2850.808031] i40e 0000:b3:00.0 transfer0: tx_timeout recovery level 1, txqueue 8
[ 2864.107174] libceph: mon2 (1)10.1.3.141:6789 session lost, hunting for new mon
[ 2864.375097] watchdog: BUG: soft lockup - CPU#0 stuck for 26s! [kworker/0:6:55453]
[ 2864.383202] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2864.383262]  async_memcpy
[ 2864.399097] watchdog: BUG: soft lockup - CPU#2 stuck for 26s! [kworker/2:1:54788]
[ 2864.451097] watchdog: BUG: soft lockup - CPU#11 stuck for 22s! [kworker/11:1:54723]
[ 2864.451101] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2864.451149]  async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2864.451166] CPU: 11 PID: 54723 Comm: kworker/11:1 Tainted: G      D W         5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2864.451168] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2864.451170] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2864.451193] RIP: 0010:native_queued_spin_lock_slowpath+0x1e2/0x230
[ 2864.451198] Code: 4d 63 f6 49 81 c5 00 19 03 00 49 81 fe ff 1f 00 00 77 49 4e 03 2c f5 e0 5a 8f ad 4d 89 65 00 41 8b 44 24 08 85 c0 75 0b f3 90 <41> 8b 44 24 08 85 c0 74 f5 49 8b 0c 24 48 85 c9 0f 84 61 ff ff ff
[ 2864.451200] RSP: 0018:ffffb0fd81407be0 EFLAGS: 00000246
[ 2864.451202] RAX: 0000000000000000 RBX: ffff909e085d1d48 RCX: 000000000000000e
[ 2864.451203] RDX: 0000000000300000 RSI: 0000000000300000 RDI: ffff909e085d1d48
[ 2864.451204] RBP: ffffb0fd81407c08 R08: ffff909e085d2090 R09: ffffb0fd81407ac0
[ 2864.451205] R10: ffff909eb2d05850 R11: 00000000cf4c4c40 R12: ffff90fb80ef1900
[ 2864.451206] R13: ffff90fb80f71900 R14: 000000000000000d R15: ffff909e085d2090
[ 2864.451207] FS:  0000000000000000(0000) GS:ffff90fb80ec0000(0000) knlGS:0000000000000000
[ 2864.451209] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2864.451210] CR2: 000055576fd38380 CR3: 00000029967c2001 CR4: 00000000007706e0
[ 2864.451212] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2864.451213] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2864.451214] PKRU: 55555554
[ 2864.451214] Call Trace:
[ 2864.451216]  <TASK>
[ 2864.451218]  _raw_spin_lock+0x22/0x30
[ 2864.451223]  ceph_handle_caps+0x3fa/0xe80 [ceph]
[ 2864.451244]  mds_dispatch+0x11f/0x320 [ceph]
[ 2864.451259]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2864.451276]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2864.451288]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2864.451303]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2864.451315]  process_one_work+0x228/0x3d0
[ 2864.451318]  worker_thread+0x4d/0x3f0
[ 2864.451321]  ? process_one_work+0x3d0/0x3d0
[ 2864.451323]  kthread+0x127/0x150
[ 2864.451325]  ? set_kthread_struct+0x50/0x50
[ 2864.451327]  ret_from_fork+0x1f/0x30
[ 2864.451331]  </TASK>
[ 2864.455097] watchdog: BUG: soft lockup - CPU#13 stuck for 22s! [kworker/13:7:54728]
[ 2864.455101] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2864.455147]  async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2864.455161] CPU: 13 PID: 54728 Comm: kworker/13:7 Tainted: G      D W    L    5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2864.455164] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2864.455166] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2864.455183] RIP: 0010:native_queued_spin_lock_slowpath+0x1e7/0x230
[ 2864.455187] Code: c5 00 19 03 00 49 81 fe ff 1f 00 00 77 49 4e 03 2c f5 e0 5a 8f ad 4d 89 65 00 41 8b 44 24 08 85 c0 75 0b f3 90 41 8b 44 24 08 <85> c0 74 f5 49 8b 0c 24 48 85 c9 0f 84 61 ff ff ff 0f 0d 09 e9 59
[ 2864.455189] RSP: 0018:ffffb0fd8143fbe0 EFLAGS: 00000246
[ 2864.455191] RAX: 0000000000000000 RBX: ffff909e085d1d48 RCX: 0000000000000001
[ 2864.455192] RDX: 0000000000380000 RSI: 0000000000380000 RDI: ffff909e085d1d48
[ 2864.455193] RBP: ffffb0fd8143fc08 R08: ffff909e085d2090 R09: ffffb0fd8143fac0
[ 2864.455194] R10: ffff909dcba0bc50 R11: 0000000087e3a640 R12: ffff90fb80f71900
[ 2864.455196] R13: ffff90fb80c31900 R14: 0000000000000000 R15: ffff909e085d2090
[ 2864.455197] FS:  0000000000000000(0000) GS:ffff90fb80f40000(0000) knlGS:0000000000000000
[ 2864.455198] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2864.455199] CR2: 00005651f16d7280 CR3: 00000001205f4006 CR4: 00000000007706e0
[ 2864.455201] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2864.455202] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2864.455203] PKRU: 55555554
[ 2864.455203] Call Trace:
[ 2864.455205]  <TASK>
[ 2864.455206]  _raw_spin_lock+0x22/0x30
[ 2864.455211]  ceph_handle_caps+0x3fa/0xe80 [ceph]
[ 2864.455229]  mds_dispatch+0x11f/0x320 [ceph]
[ 2864.455243]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2864.455260]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2864.455273]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2864.455288]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2864.455299]  process_one_work+0x228/0x3d0
[ 2864.455303]  worker_thread+0x4d/0x3f0
[ 2864.455305]  ? process_one_work+0x3d0/0x3d0
[ 2864.455308]  kthread+0x127/0x150
[ 2864.455310]  ? set_kthread_struct+0x50/0x50
[ 2864.455313]  ret_from_fork+0x1f/0x30
[ 2864.455317]  </TASK>
[ 2864.459097] watchdog: BUG: soft lockup - CPU#15 stuck for 22s! [kworker/15:2:284]
[ 2864.459101] Modules linked in: binfmt_misc tcp_diag udp_diag inet_diag ceph libceph fscache netfs overlay 8021q garp mrp stp llc ip6t_REJECT nf_reject_ipv6 xt_hl ip6table_filter ip6_tables xt_LOG nf_log_syslog ipt_REJECT nf_reject_ipv4 xt_multiport xt_comment xt_state iptable_filter bpfilter intel_rapl_msr intel_rapl_common isst_if_common skx_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm ast drm_vram_helper drm_ttm_helper irdma ttm crct10dif_pclmul ghash_clmulni_intel aesni_intel ice drm_kms_helper sch_fq_codel crypto_simd cryptd cec ib_uverbs rc_core rapl i2c_algo_bit ib_core intel_cstate fb_sys_fops syscopyarea sysfillrect joydev input_leds sysimgblt mei_me ioatdma mei intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov
[ 2864.459146]  async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2864.459159] CPU: 15 PID: 284 Comm: kworker/15:2 Tainted: G      D W    L    5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2864.459162] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2864.459163] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2864.459177] RIP: 0010:native_queued_spin_lock_slowpath+0x1e2/0x230
[ 2864.459181] Code: 4d 63 f6 49 81 c5 00 19 03 00 49 81 fe ff 1f 00 00 77 49 4e 03 2c f5 e0 5a 8f ad 4d 89 65 00 41 8b 44 24 08 85 c0 75 0b f3 90 <41> 8b 44 24 08 85 c0 74 f5 49 8b 0c 24 48 85 c9 0f 84 61 ff ff ff
[ 2864.459182] RSP: 0018:ffffb0fd8140fbe0 EFLAGS: 00000246
[ 2864.459184] RAX: 0000000000000000 RBX: ffff909e085d1d48 RCX: 000000000000000c
[ 2864.459185] RDX: 0000000000400000 RSI: 0000000000400000 RDI: ffff909e085d1d48
[ 2864.459187] RBP: ffffb0fd8140fc08 R08: ffff909e085d2090 R09: ffffb0fd8140fac0
[ 2864.459188] R10: ffff90f5242acc50 R11: 00000000d2249780 R12: ffff90fb80ff1900
[ 2864.459189] R13: ffff90fb80ef1900 R14: 000000000000000b R15: ffff909e085d2090
[ 2864.459190] FS:  0000000000000000(0000) GS:ffff90fb80fc0000(0000) knlGS:0000000000000000
[ 2864.459192] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2864.459193] CR2: 0000559cade9dd20 CR3: 00000029967c2001 CR4: 00000000007706e0
[ 2864.459194] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2864.459195] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2864.459196] PKRU: 55555554
[ 2864.459197] Call Trace:
[ 2864.459197]  <TASK>
[ 2864.459199]  _raw_spin_lock+0x22/0x30
[ 2864.459202]  ceph_handle_caps+0x3fa/0xe80 [ceph]
[ 2864.459219]  mds_dispatch+0x11f/0x320 [ceph]
[ 2864.459233]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2864.459250]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2864.459262]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2864.459277]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2864.459288]  process_one_work+0x228/0x3d0
[ 2864.459291]  worker_thread+0x4d/0x3f0
[ 2864.459294]  ? process_one_work+0x3d0/0x3d0
[ 2864.459296]  kthread+0x127/0x150
[ 2864.459298]  ? set_kthread_struct+0x50/0x50
[ 2864.459301]  ret_from_fork+0x1f/0x30
[ 2864.459304]  </TASK>
[ 2864.475259]  async_pq
[ 2864.478668] Modules linked in:
[ 2864.486885]  async_xor
[ 2864.495347]  binfmt_misc
[ 2864.588758]  async_tx
[ 2864.615033]  tcp_diag
[ 2864.626323]  xor raid6_pq
[ 2864.634699]  udp_diag
[ 2864.641096]  libcrc32c
[ 2864.648241]  inet_diag
[ 2864.668948]  raid0
[ 2864.675111]  ceph
[ 2864.683227]  multipath
[ 2864.691344]  libceph
[ 2864.699499]  linear
[ 2864.707653]  fscache
[ 2864.715780]  ses
[ 2864.724836]  netfs overlay
[ 2864.731574]  enclosure
[ 2864.739682]  8021q
[ 2864.747780]  raid1
[ 2864.755874]  garp
[ 2864.759521]  hid_generic
[ 2864.762834]  mrp
[ 2864.765783]  usbhid
[ 2864.770285]  stp
[ 2864.775789]  hid
[ 2864.780938]  llc
[ 2864.787211]  mpt3sas
[ 2864.793501]  ip6t_REJECT
[ 2864.799568]  raid_class
[ 2864.805183]  nf_reject_ipv6
[ 2864.809943]  ahci
[ 2864.814339]  xt_hl
[ 2864.819275]  xhci_pci
[ 2864.823231]  ip6table_filter
[ 2864.828148]  i2c_i801
[ 2864.832441]  ip6_tables
[ 2864.835305]  crc32_pclmul
[ 2864.843677]  xt_LOG nf_log_syslog
[ 2864.935895]  i40e scsi_transport_sas
[ 2864.961758]  ipt_REJECT
[ 2864.972817]  lpc_ich
[ 2864.981015]  nf_reject_ipv4
[ 2864.987211]  i2c_smbus
[ 2864.994046]  xt_multiport xt_comment
[ 2865.014164]  xhci_pci_renesas
[ 2865.020098]  xt_state
[ 2865.027935]  libahci
[ 2865.035778]  iptable_filter
[ 2865.043625]  wmi
[ 2865.051474]  bpfilter
[ 2865.059315] 
[ 2865.068113]  intel_rapl_msr
[ 2865.074512] CPU: 0 PID: 55453 Comm: kworker/0:6 Tainted: G      D W    L    5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2865.082344]  intel_rapl_common
[ 2865.090128] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2865.097964]  isst_if_common
[ 2865.101334] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2865.104470]  skx_edac
[ 2865.107265] 
[ 2865.111631]  nfit
[ 2865.116919] RIP: 0010:native_queued_spin_lock_slowpath+0x15b/0x230
[ 2865.121843]  x86_pkg_temp_thermal
[ 2865.127947] Code: 5e 5d c3 cc cc cc cc 83 c6 01 c1 e2 10 c1 e6 12 09 f2 89 d0 c1 e8 10 66 87 43 02 89 c1 c1 e1 10 75 53 31 c9 eb 02 f3 90 8b 03 <66> 85 c0 75 f7 89 c6 66 31 f6 39 f2 0f 84 93 00 00 00 c6 03 01 48
[ 2865.134123]  intel_powerclamp
[ 2865.140053] RSP: 0018:ffffb0fd84fffb48 EFLAGS: 00000202
[ 2865.145536]  coretemp
[ 2865.150207] 
[ 2865.154557]  kvm_intel
[ 2865.159423] RAX: 0000000000400101 RBX: ffff909e085d1d48 RCX: 0000000000000000
[ 2865.163353]  kvm
[ 2865.168229] RDX: 0000000000040000 RSI: 0000000000040000 RDI: ffff909e085d1d48
[ 2865.172512]  ast
[ 2865.175397] RBP: ffffb0fd84fffb70 R08: ffff909e085d2090 R09: ffffb0fd84fffac0
[ 2865.183589]  drm_vram_helper drm_ttm_helper
[ 2865.275712] R10: ffff909ddac67850 R11: 00000000d86ef7a0 R12: ffff90fb80c31900
[ 2865.301496]  irdma
[ 2865.312389] R13: ffff909eadef3028 R14: 0000000000000003 R15: ffff909dd197e000
[ 2865.320575]  ttm
[ 2865.326720] FS:  0000000000000000(0000) GS:ffff90fb80c00000(0000) knlGS:0000000000000000
[ 2865.333603]  crct10dif_pclmul
[ 2865.353700] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2865.359642]  ghash_clmulni_intel
[ 2865.367821] CR2: 000055576f906160 CR3: 0000000246c04003 CR4: 00000000007706f0
[ 2865.375662]  aesni_intel
[ 2865.383507] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2865.391361]  ice drm_kms_helper
[ 2865.399171] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2865.407981]  sch_fq_codel
[ 2865.414445] PKRU: 55555554
[ 2865.422291]  crypto_simd
[ 2865.430076] Call Trace:
[ 2865.437910]  cryptd
[ 2865.441269]  <TASK>
[ 2865.444413]  cec
[ 2865.447206]  _raw_spin_lock+0x22/0x30
[ 2865.451560]  ib_uverbs
[ 2865.456877]  handle_cap_export+0x9e/0x460 [ceph]
[ 2865.461839]  rc_core rapl
[ 2865.467943]  ceph_handle_caps+0x6d4/0xe80 [ceph]
[ 2865.474078]  i2c_algo_bit
[ 2865.480002]  mds_dispatch+0x11f/0x320 [ceph]
[ 2865.485484]  ib_core
[ 2865.490143]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2865.494462]  intel_cstate
[ 2865.499355]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2865.503284]  fb_sys_fops
[ 2865.508165]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2865.512438]  syscopyarea
[ 2865.515317]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2865.518287]  sysfillrect
[ 2865.521977]  process_one_work+0x228/0x3d0
[ 2865.524957]  joydev
[ 2865.528134]  worker_thread+0x4d/0x3f0
[ 2865.531026]  input_leds
[ 2865.533903]  ? process_one_work+0x3d0/0x3d0
[ 2865.537101]  sysimgblt
[ 2865.539931]  kthread+0x127/0x150
[ 2865.542821]  mei_me
[ 2865.545655]  ? set_kthread_struct+0x50/0x50
[ 2865.548158]  ioatdma
[ 2865.550522]  ret_from_fork+0x1f/0x30
[ 2865.553322]  mei
[ 2865.555938]  </TASK>
[ 2865.558441]  intel_pch_thermal dca ipmi_ssif mac_hid acpi_power_meter acpi_pad acpi_ipmi ipmi_si ipmi_devintf ipmi_msghandler bonding tls xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 drm nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid0 multipath linear ses enclosure raid1 hid_generic usbhid hid mpt3sas raid_class ahci xhci_pci i2c_i801 crc32_pclmul i40e scsi_transport_sas lpc_ich i2c_smbus xhci_pci_renesas libahci wmi
[ 2866.028815] CPU: 2 PID: 54788 Comm: kworker/2:1 Tainted: G      D W    L    5.15.0-48-generic #54~20.04.1-Ubuntu
[ 2866.039516] Hardware name: Supermicro Super Server/X11SPi-TF, BIOS 3.3 02/21/2020
[ 2866.047526] Workqueue: ceph-msgr ceph_con_workfn [libceph]
[ 2866.053514] RIP: 0010:native_queued_spin_lock_slowpath+0x79/0x230
[ 2866.060131] Code: 7c f0 0f ba 2b 08 0f 92 c0 0f b6 c0 c1 e0 08 89 c2 8b 03 30 e4 09 d0 a9 00 01 ff ff 75 56 85 c0 74 0e 8b 03 84 c0 74 08 f3 90 <8b> 03 84 c0 75 f8 b8 01 00 00 00 66 89 03 48 83 c4 08 5b 41 5c 41
[ 2866.079957] RSP: 0018:ffffb0fd813dfb48 EFLAGS: 00000202
[ 2866.085720] RAX: 0000000000400101 RBX: ffff909e085d1d48 RCX: ffff909dc7e15000
[ 2866.093370] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff909e085d1d48
[ 2866.101017] RBP: ffffb0fd813dfb70 R08: ffff909e085d2090 R09: ffffb0fd813dfac0
[ 2866.108690] R10: ffff909dcba08450 R11: 00000000c71e0480 R12: 0000000000000002
[ 2866.116398] R13: ffff909dc7e15028 R14: 0000000000000003 R15: ffff909dd197e000
[ 2866.124105] FS:  0000000000000000(0000) GS:ffff90fb80c80000(0000) knlGS:0000000000000000
[ 2866.132759] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2866.139059] CR2: 00005561e74ab380 CR3: 00000001e800e005 CR4: 00000000007706e0
[ 2866.146809] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2866.154505] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2866.162195] PKRU: 55555554
[ 2866.165461] Call Trace:
[ 2866.168502]  <TASK>
[ 2866.171196]  _raw_spin_lock+0x22/0x30
[ 2866.175456]  handle_cap_export+0x9e/0x460 [ceph]
[ 2866.180666]  ceph_handle_caps+0x6d4/0xe80 [ceph]
[ 2866.185891]  mds_dispatch+0x11f/0x320 [ceph]
[ 2866.190754]  ? read_partial_message+0x22e/0x5e0 [libceph]
[ 2866.196741]  ceph_con_process_message+0x7a/0x150 [libceph]
[ 2866.202787]  ceph_con_v1_try_read+0x341/0x8d0 [libceph]
[ 2866.208605]  ceph_con_workfn+0x332/0x680 [libceph]
[ 2866.213987]  process_one_work+0x228/0x3d0
[ 2866.218539]  worker_thread+0x4d/0x3f0
[ 2866.222760]  ? process_one_work+0x3d0/0x3d0
[ 2866.227531]  kthread+0x127/0x150
[ 2866.231338]  ? set_kthread_struct+0x50/0x50
[ 2866.236105]  ret_from_fork+0x1f/0x30
[ 2866.240266]  </TASK>
[ 2881.003178] libceph: mon0 (1)10.1.3.139:6789 session lost, hunting for new mon
[ 2881.771180] ceph: mds7 caps stale

It takes a couple of MDS fails or even concurrent fails to reproduce the issue (on every MDS fail, "ceph: update_snap_trace error -5" is logged, but that's usually all).

Both directories that are mounted for the test have a quota (max bytes, no max files) and there are snapshots in a common ancestor directory.

I'm happy to provide any further information.

Actions #1

Updated by Andreas Teuchert over 1 year ago

When mounting "/" (the whole CephFS) instead of the individual directories, MDS failovers don't cause any issues (not even "ceph: update_snap_trace error -5").

Actions #2

Updated by Andreas Teuchert over 1 year ago

Minor correction: "ceph: update_snap_trace error -5" is still seen in dmesg after MDS failovers when mounting the whole FS.

Actions #3

Updated by Xiubo Li over 1 year ago

  • Status changed from New to Duplicate
  • Parent task set to #57686

The MDS sent a corrupted snap trace and then triggered the kernel crash. So the MDS side also buggy.

Actions

Also available in: Atom PDF