openzfs / zfs

OpenZFS on Linux and FreeBSD
https://openzfs.github.io/openzfs-docs
Other
10.45k stars 1.73k forks source link

BUG: unable to handle page fault #14980

Open cainiaocome opened 1 year ago

cainiaocome commented 1 year ago

System information

Type Version/Name
Distribution Name proxmox
Distribution Version 7.2
Kernel Version #1 SMP PVE 5.15.30-3 (Fri, 22 Apr 2022 18:08:27 +0200)
Architecture x86-64
OpenZFS Version zfs-2.1.4-pve1

Describe the problem you're observing

Random error BUG: unable to handle page fault for address. I collected multiple kernel log for it and attached. You can search the error in these logs to find them. I ran memtest about 1 day and didn't find any ram error. And considering all errors seem coming from arc evict related process, I don't think this is because of ram defect or else other processes or modules should also randomly crash.

Describe how to reproduce the problem

I can only reproduce it on my own machine so I am not sure how other people can reproduce it. I can provide some background though.

➜  backedup-log-for-analysis cat /etc/modprobe.d/zfs.conf
# Persistent L2ARC, is 1 by default so this option shouldn't be necessary.
options zfs l2arc_rebuild_enabled=1

# NoPrefetch = False to also cache synchronous reads.
options zfs l2arc_noprefetch=0

# Increase the maximum write from 8mb/s to 500mb/s
options zfs l2arc_write_max=536870912

# At startup it'll boost to 1GB/s if needed.
options zfs l2arc_write_boost=1073741824

➜  backedup-log-for-analysis zpool status -v
  pool: hdpool
 state: ONLINE
  scan: scrub repaired 0B in 03:27:35 with 0 errors on Mon Jun 12 12:46:50 2023
config:

    NAME                                                  STATE     READ WRITE CKSUM
    hdpool                                                ONLINE       0     0     0
      raidz1-0                                            ONLINE       0     0     0
        ata-ST2000DM001-1ER164_W8E0F1LV                   ONLINE       0     0     0
        ata-TOSHIBA_HDWD130_50QVXDNAS                     ONLINE       0     0     0
    logs
      /root/sparsefiles-for-zfs-cache-and-zil/hdpool-zil  ONLINE       0     0     0

errors: No known data errors
➜  backedup-log-for-analysis

Include any warning/errors/backtraces from the system logs

kern-1.log kern-2.log kern-3.log kern-4.log

rincebrain commented 1 year ago

Since the author didn't, let me just inline those here for ease of future searching, since I don't believe github search indexes attachments...

Jun  7 17:35:56 pve2 kernel: [686631.862625] general protection fault, probably for non-canonical address 0x8003000001c0428: 0000 [#1] SMP NOPTI
Jun  7 17:35:56 pve2 kernel: [686631.862672] CPU: 1 PID: 685 Comm: arc_evict Tainted: P           O      5.15.30-2-pve #1
Jun  7 17:35:56 pve2 kernel: [686631.862705] Hardware name: Micro-Star International Co., Ltd MS-7B86/B450 GAMING PLUS MAX (MS-7B86), BIOS H.G0 07/26/2022
Jun  7 17:35:56 pve2 kernel: [686631.862741] RIP: 0010:abd_free_chunks+0xb2/0x1c0 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.862867] Code: ff ff ff 3f 48 c7 c6 ff ff ff ff 83 c3 01 e8 95 c6 2c d3 4c 89 f7 e8 1d 6b 29 d3 49 89 c6 39 5d bc 74 79 4d 8b 26 49 83 e4 fc <49> c7 44 24 28 00 00 00 00 f0 41 80 64 24 01 df 49 8b 44 24 08 48
Jun  7 17:35:56 pve2 kernel: [686631.862937] RSP: 0018:ffffa67b812b3c58 EFLAGS: 00010206
Jun  7 17:35:56 pve2 kernel: [686631.862958] RAX: 0000000000000001 RBX: 0000000000000000 RCX: 0000000000000001
Jun  7 17:35:56 pve2 kernel: [686631.862983] RDX: 0000000000000002 RSI: fffffffffffff000 RDI: ffff9a5a342e1a90
Jun  7 17:35:56 pve2 kernel: [686631.863012] RBP: ffffa67b812b3ca8 R08: 0000000000000001 R09: ffff9a62b243e580
Jun  7 17:35:56 pve2 kernel: [686631.863040] R10: 0000000000000001 R11: ffff9a5960a456e8 R12: 08003000001c0400
Jun  7 17:35:56 pve2 kernel: [686631.863066] R13: ffff9a5a342e1a90 R14: ffff9a59d9493640 R15: ffff9a5653664300
Jun  7 17:35:56 pve2 kernel: [686631.863094] FS:  0000000000000000(0000) GS:ffff9a653ea40000(0000) knlGS:0000000000000000
Jun  7 17:35:56 pve2 kernel: [686631.863125] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun  7 17:35:56 pve2 kernel: [686631.863148] CR2: 00007f6eaa19f8c0 CR3: 0000000235e04000 CR4: 00000000003506e0
Jun  7 17:35:56 pve2 kernel: [686631.863179] Call Trace:
Jun  7 17:35:56 pve2 kernel: [686631.863190]  <TASK>
Jun  7 17:35:56 pve2 kernel: [686631.863201]  abd_free_linear_page+0x24/0x40 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863319]  abd_free+0x1c8/0x1d0 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863408]  arc_hdr_free_abd+0x1b3/0x2d0 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863501]  arc_evict_state+0x817/0xa40 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863592]  arc_evict_cb+0x947/0xf10 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863683]  ? sigprocmask+0xa8/0xe0
Jun  7 17:35:56 pve2 kernel: [686631.863704]  zthr_procedure+0x13e/0x160 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863812]  ? zrl_is_locked+0x20/0x20 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.863919]  thread_generic_wrapper+0x61/0x70 [spl]
Jun  7 17:35:56 pve2 kernel: [686631.863946]  ? __thread_exit+0x20/0x20 [spl]
Jun  7 17:35:56 pve2 kernel: [686631.863970]  kthread+0x127/0x150
Jun  7 17:35:56 pve2 kernel: [686631.863987]  ? set_kthread_struct+0x50/0x50
Jun  7 17:35:56 pve2 kernel: [686631.864006]  ret_from_fork+0x1f/0x30
Jun  7 17:35:56 pve2 kernel: [686631.864024]  </TASK>
Jun  7 17:35:56 pve2 kernel: [686631.864033] Modules linked in: tcp_diag inet_diag ebtable_filter ebtables ip_set ip6table_raw iptable_raw ip6table_filter ip6_tables iptable_filter bpfilter nf_tables bonding tls softdog nfnetlink_log nfnetlink intel_rapl_msr intel_rapl_common edac_mce_amd nouveau kvm_amd snd_hda_codec_realtek mxm_wmi video snd_hda_codec_generic drm_ttm_helper ledtrig_audio ttm snd_hda_codec_hdmi kvm snd_hda_intel crct10dif_pclmul snd_intel_dspcfg ghash_clmulni_intel drm_kms_helper aesni_intel snd_intel_sdw_acpi snd_hda_codec cec crypto_simd zram snd_hda_core rc_core cryptd ppdev snd_hwdep i2c_algo_bit rapl fb_sys_fops snd_pcm pcspkr syscopyarea sysfillrect snd_timer sysimgblt snd zfs(PO) soundcore ccp efi_pstore wmi_bmof k10temp parport_pc zunicode(PO) parport zzstd(O) zlua(O) mac_hid zavl(PO) icp(PO) zcommon(PO) znvpair(PO) spl(O) vhost_net vhost vhost_iotlb tap ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi nct6775 hwmon_vid vfio_pci vfio_pci_core vfio_virqfd
Jun  7 17:35:56 pve2 kernel: [686631.864096]  irqbypass vfio_iommu_type1 vfio drm sunrpc ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear simplefb crc32_pclmul xhci_pci r8169 xhci_pci_renesas i2c_piix4 realtek ahci xhci_hcd libahci wmi gpio_amdpt gpio_generic
Jun  7 17:35:56 pve2 kernel: [686631.870378] ---[ end trace 5fd5735572da9dd1 ]---
Jun  7 17:35:56 pve2 kernel: [686631.911259] RIP: 0010:abd_free_chunks+0xb2/0x1c0 [zfs]
Jun  7 17:35:56 pve2 kernel: [686631.912527] Code: ff ff ff 3f 48 c7 c6 ff ff ff ff 83 c3 01 e8 95 c6 2c d3 4c 89 f7 e8 1d 6b 29 d3 49 89 c6 39 5d bc 74 79 4d 8b 26 49 83 e4 fc <49> c7 44 24 28 00 00 00 00 f0 41 80 64 24 01 df 49 8b 44 24 08 48
Jun  7 17:35:56 pve2 kernel: [686631.914053] RSP: 0018:ffffa67b812b3c58 EFLAGS: 00010206
Jun  7 17:35:56 pve2 kernel: [686631.914870] RAX: 0000000000000001 RBX: 0000000000000000 RCX: 0000000000000001
Jun  7 17:35:56 pve2 kernel: [686631.915714] RDX: 0000000000000002 RSI: fffffffffffff000 RDI: ffff9a5a342e1a90
Jun  7 17:35:56 pve2 kernel: [686631.916540] RBP: ffffa67b812b3ca8 R08: 0000000000000001 R09: ffff9a62b243e580
Jun  7 17:35:56 pve2 kernel: [686631.917317] R10: 0000000000000001 R11: ffff9a5960a456e8 R12: 08003000001c0400
Jun  7 17:35:56 pve2 kernel: [686631.918137] R13: ffff9a5a342e1a90 R14: ffff9a59d9493640 R15: ffff9a5653664300
Jun  7 17:35:56 pve2 kernel: [686631.918962] FS:  0000000000000000(0000) GS:ffff9a653ea40000(0000) knlGS:0000000000000000
Jun  7 17:35:56 pve2 kernel: [686631.919637] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun  7 17:35:56 pve2 kernel: [686631.920366] CR2: 00007f6eaa19f8c0 CR3: 0000000235e04000 CR4: 00000000003506e0

Jun 12 13:52:13 pve2 kernel: [195901.281062] #PF: supervisor read access in kernel mode
Jun 12 13:52:13 pve2 kernel: [195901.281088] #PF: error_code(0x0000) - not-present page
Jun 12 13:52:13 pve2 kernel: [195901.281112] PGD 0 P4D 0 
Jun 12 13:52:13 pve2 kernel: [195901.281129] Oops: 0000 [#1] SMP NOPTI
Jun 12 13:52:13 pve2 kernel: [195901.281150] CPU: 0 PID: 664 Comm: arc_evict Tainted: P           O      5.15.30-2-pve #1
Jun 12 13:52:13 pve2 kernel: [195901.281190] Hardware name: Micro-Star International Co., Ltd MS-7B86/B450 GAMING PLUS MAX (MS-7B86), BIOS H.G0 07/26/2022
Jun 12 13:52:13 pve2 kernel: [195901.281238] RIP: 0010:buf_hash_remove+0x7c/0xb0 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.281350] Code: 48 89 02 48 c7 43 20 00 00 00 00 81 63 28 7f ff ff ff f0 48 ff 0d c4 bf 22 00 48 8b 05 35 40 25 00 48 8b 04 c8 48 85 c0 74 07 <48> 83 78 20 00 74 06 48 8b 5d f8 c9 c3 ba ff ff ff 3f 48 c7 c6 ff
Jun 12 13:52:13 pve2 kernel: [195901.281433] RSP: 0018:ffffaf6841c1bcf8 EFLAGS: 00010206
Jun 12 13:52:13 pve2 kernel: [195901.281458] RAX: 0000000080000000 RBX: ffff8d2bf9277400 RCX: 00000000005e24f1
Jun 12 13:52:13 pve2 kernel: [195901.281494] RDX: ffffaf6845113788 RSI: 0000000000000010 RDI: c312db6e09667155
Jun 12 13:52:13 pve2 kernel: [195901.281528] RBP: ffffaf6841c1bd00 R08: 9ae16a3b2f90408f R09: 9ae16a3b2f90404f
Jun 12 13:52:13 pve2 kernel: [195901.281562] R10: 0000000000000001 R11: ffff8d291d733040 R12: ffff8d2bf9277400
Jun 12 13:52:13 pve2 kernel: [195901.281597] R13: ffffffffc0e01a80 R14: 0000000000000001 R15: ffff8d28147a7080
Jun 12 13:52:13 pve2 kernel: [195901.281633] FS:  0000000000000000(0000) GS:ffff8d36fea00000(0000) knlGS:0000000000000000
Jun 12 13:52:13 pve2 kernel: [195901.281674] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 12 13:52:13 pve2 kernel: [195901.281701] CR2: 0000000080000020 CR3: 0000000d872e8000 CR4: 00000000003506f0
Jun 12 13:52:13 pve2 kernel: [195901.281735] Call Trace:
Jun 12 13:52:13 pve2 kernel: [195901.281749]  <TASK>
Jun 12 13:52:13 pve2 kernel: [195901.281763]  arc_change_state.constprop.0+0x291/0x580 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.281877]  arc_evict_state+0x617/0xa40 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.281975]  arc_evict_cb+0x86e/0xf10 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.282076]  ? sigprocmask+0xa8/0xe0
Jun 12 13:52:13 pve2 kernel: [195901.282099]  zthr_procedure+0x13e/0x160 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.282223]  ? zrl_is_locked+0x20/0x20 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.282349]  thread_generic_wrapper+0x61/0x70 [spl]
Jun 12 13:52:13 pve2 kernel: [195901.282383]  ? __thread_exit+0x20/0x20 [spl]
Jun 12 13:52:13 pve2 kernel: [195901.282410]  kthread+0x127/0x150
Jun 12 13:52:13 pve2 kernel: [195901.282430]  ? set_kthread_struct+0x50/0x50
Jun 12 13:52:13 pve2 kernel: [195901.282453]  ret_from_fork+0x1f/0x30
Jun 12 13:52:13 pve2 kernel: [195901.282477]  </TASK>
Jun 12 13:52:13 pve2 kernel: [195901.282490] Modules linked in: ebtable_filter ebtables ip_set ip6table_raw iptable_raw ip6table_filter ip6_tables iptable_filter bpfilter nf_tables bonding tls softdog nfnetlink_log nfnetlink intel_rapl_msr intel_rapl_common edac_mce_amd snd_hda_codec_realtek snd_hda_codec_generic kvm_amd nouveau ledtrig_audio snd_hda_codec_hdmi kvm mxm_wmi snd_hda_intel video snd_intel_dspcfg crct10dif_pclmul drm_ttm_helper ttm snd_intel_sdw_acpi ghash_clmulni_intel snd_hda_codec aesni_intel drm_kms_helper snd_hda_core crypto_simd zram cryptd ppdev cec snd_hwdep rc_core snd_pcm rapl i2c_algo_bit fb_sys_fops snd_timer syscopyarea snd sysfillrect sysimgblt soundcore ccp pcspkr k10temp efi_pstore zfs(PO) wmi_bmof parport_pc parport zunicode(PO) mac_hid zzstd(O) zlua(O) zavl(PO) icp(PO) zcommon(PO) znvpair(PO) spl(O) vhost_net vhost vhost_iotlb tap ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi nct6775 hwmon_vid vfio_pci vfio_pci_core vfio_virqfd irqbypass
Jun 12 13:52:13 pve2 kernel: [195901.282541]  vfio_iommu_type1 vfio drm sunrpc ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear simplefb crc32_pclmul i2c_piix4 xhci_pci xhci_pci_renesas r8169 realtek ahci xhci_hcd libahci wmi gpio_amdpt gpio_generic
Jun 12 13:52:13 pve2 kernel: [195901.287510] CR2: 0000000080000020
Jun 12 13:52:13 pve2 kernel: [195901.288159] ---[ end trace 75a8cb7086a4c706 ]---
Jun 12 13:52:13 pve2 kernel: [195901.325366] RIP: 0010:buf_hash_remove+0x7c/0xb0 [zfs]
Jun 12 13:52:13 pve2 kernel: [195901.326069] Code: 48 89 02 48 c7 43 20 00 00 00 00 81 63 28 7f ff ff ff f0 48 ff 0d c4 bf 22 00 48 8b 05 35 40 25 00 48 8b 04 c8 48 85 c0 74 07 <48> 83 78 20 00 74 06 48 8b 5d f8 c9 c3 ba ff ff ff 3f 48 c7 c6 ff
Jun 12 13:52:13 pve2 kernel: [195901.327374] RSP: 0018:ffffaf6841c1bcf8 EFLAGS: 00010206
Jun 12 13:52:13 pve2 kernel: [195901.328030] RAX: 0000000080000000 RBX: ffff8d2bf9277400 RCX: 00000000005e24f1
Jun 12 13:52:13 pve2 kernel: [195901.328686] RDX: ffffaf6845113788 RSI: 0000000000000010 RDI: c312db6e09667155
Jun 12 13:52:13 pve2 kernel: [195901.329349] RBP: ffffaf6841c1bd00 R08: 9ae16a3b2f90408f R09: 9ae16a3b2f90404f
Jun 12 13:52:13 pve2 kernel: [195901.330010] R10: 0000000000000001 R11: ffff8d291d733040 R12: ffff8d2bf9277400
Jun 12 13:52:13 pve2 kernel: [195901.330664] R13: ffffffffc0e01a80 R14: 0000000000000001 R15: ffff8d28147a7080
Jun 12 13:52:13 pve2 kernel: [195901.331306] FS:  0000000000000000(0000) GS:ffff8d36fea00000(0000) knlGS:0000000000000000
Jun 12 13:52:13 pve2 kernel: [195901.331967] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 12 13:52:13 pve2 kernel: [195901.332600] CR2: 0000000080000020 CR3: 0000000d872e8000 CR4: 00000000003506f0
Jun 14 18:57:45 pve2 kernel: [173638.343278] BUG: unable to handle page fault for address: 0000000040000040
Jun 14 18:57:45 pve2 kernel: [173638.343309] #PF: supervisor read access in kernel mode
Jun 14 18:57:45 pve2 kernel: [173638.343325] #PF: error_code(0x0000) - not-present page
Jun 14 18:57:45 pve2 kernel: [173638.343339] PGD 0 P4D 0 
Jun 14 18:57:45 pve2 kernel: [173638.343348] Oops: 0000 [#1] SMP NOPTI
Jun 14 18:57:45 pve2 kernel: [173638.343360] CPU: 14 PID: 802522 Comm: z_wr_int_2 Tainted: P           O      5.15.30-2-pve #1
Jun 14 18:57:45 pve2 kernel: [173638.343382] Hardware name: Micro-Star International Co., Ltd MS-7B86/B450 GAMING PLUS MAX (MS-7B86), BIOS H.G0 07/26/2022
Jun 14 18:57:45 pve2 kernel: [173638.343409] RIP: 0010:arc_evictable_space_decrement+0xe7/0x200 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.343514] Code: db 75 27 5b 41 5c 41 5d 41 5e 41 5f 5d c3 41 0f b7 44 24 2c c1 e0 09 48 98 48 f7 d8 f0 49 0f c1 06 48 8b 5b 08 48 85 db 74 d9 <4c> 8b 6b 40 4c 8b 23 4d 85 ed 74 12 49 8b bc 24 38 01 00 00 48 85
Jun 14 18:57:45 pve2 kernel: [173638.343566] RSP: 0018:ffffbade2e657b30 EFLAGS: 00010206
Jun 14 18:57:45 pve2 kernel: [173638.343585] RAX: 0000000000040000 RBX: 0000000040000000 RCX: 0000000000000018
Jun 14 18:57:45 pve2 kernel: [173638.343608] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff9abfb14ec3c0
Jun 14 18:57:45 pve2 kernel: [173638.343629] RBP: ffffbade2e657b58 R08: 0000000000000001 R09: 0000000000000001
Jun 14 18:57:45 pve2 kernel: [173638.343647] R10: 0000000000000001 R11: ffff9abec23c2270 R12: ffffffffc0f17b40
Jun 14 18:57:45 pve2 kernel: [173638.343664] R13: 0000000000000001 R14: ffffffffc0f17bc8 R15: 0000000000000001
Jun 14 18:57:45 pve2 kernel: [173638.343682] FS:  0000000000000000(0000) GS:ffff9acabed80000(0000) knlGS:0000000000000000
Jun 14 18:57:45 pve2 kernel: [173638.343702] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 14 18:57:45 pve2 kernel: [173638.343716] CR2: 0000000040000040 CR3: 000000026400c000 CR4: 00000000003506e0
Jun 14 18:57:45 pve2 kernel: [173638.343734] Call Trace:
Jun 14 18:57:45 pve2 kernel: [173638.343742]  <TASK>
Jun 14 18:57:45 pve2 kernel: [173638.343751]  arc_change_state.constprop.0+0x4cf/0x580 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.343813]  arc_freed+0xaa/0xc0 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.343868]  zio_free_sync+0x52/0x100 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.343949]  zio_free+0xc0/0x100 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344027]  dsl_free+0x11/0x20 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344096]  dsl_dataset_block_kill+0x2b2/0x500 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344180]  dbuf_write_done+0x1ad/0x1f0 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344259]  arc_write_done+0x8c/0x420 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344341]  zio_done+0x408/0x1280 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344435]  zio_execute+0x92/0x160 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344514]  taskq_thread+0x298/0x4c0 [spl]
Jun 14 18:57:45 pve2 kernel: [173638.344531]  ? wake_up_q+0x90/0x90
Jun 14 18:57:45 pve2 kernel: [173638.344545]  ? zio_gang_tree_free+0x70/0x70 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.344624]  ? taskq_thread_spawn+0x60/0x60 [spl]
Jun 14 18:57:45 pve2 kernel: [173638.344641]  kthread+0x127/0x150
Jun 14 18:57:45 pve2 kernel: [173638.344652]  ? set_kthread_struct+0x50/0x50
Jun 14 18:57:45 pve2 kernel: [173638.345161]  ret_from_fork+0x1f/0x30
Jun 14 18:57:45 pve2 kernel: [173638.345720]  </TASK>
Jun 14 18:57:45 pve2 kernel: [173638.346243] Modules linked in: tcp_diag inet_diag ebtable_filter ebtables ip_set ip6table_raw iptable_raw ip6table_filter ip6_tables iptable_filter bpfilter nf_tables bonding tls softdog nfnetlink_log nfnetlink intel_rapl_msr intel_rapl_common nouveau mxm_wmi edac_mce_amd video drm_ttm_helper snd_hda_codec_realtek ttm kvm_amd snd_hda_codec_generic ledtrig_audio snd_hda_codec_hdmi drm_kms_helper kvm snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec snd_hda_core crct10dif_pclmul zram ppdev ghash_clmulni_intel snd_hwdep cec aesni_intel rc_core crypto_simd snd_pcm i2c_algo_bit cryptd fb_sys_fops snd_timer syscopyarea rapl sysfillrect sysimgblt snd ccp soundcore zfs(PO) efi_pstore k10temp pcspkr wmi_bmof parport_pc zunicode(PO) parport zzstd(O) mac_hid zlua(O) zavl(PO) icp(PO) zcommon(PO) znvpair(PO) spl(O) vhost_net vhost vhost_iotlb tap ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi nct6775 hwmon_vid vfio_pci vfio_pci_core vfio_virqfd
Jun 14 18:57:45 pve2 kernel: [173638.346298]  irqbypass vfio_iommu_type1 vfio drm sunrpc ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear simplefb crc32_pclmul i2c_piix4 xhci_pci r8169 xhci_pci_renesas realtek ahci xhci_hcd libahci wmi gpio_amdpt gpio_generic
Jun 14 18:57:45 pve2 kernel: [173638.352799] CR2: 0000000040000040
Jun 14 18:57:45 pve2 kernel: [173638.353438] ---[ end trace a51b6270edeaccca ]---
Jun 14 18:57:45 pve2 kernel: [173638.390682] RIP: 0010:arc_evictable_space_decrement+0xe7/0x200 [zfs]
Jun 14 18:57:45 pve2 kernel: [173638.391463] Code: db 75 27 5b 41 5c 41 5d 41 5e 41 5f 5d c3 41 0f b7 44 24 2c c1 e0 09 48 98 48 f7 d8 f0 49 0f c1 06 48 8b 5b 08 48 85 db 74 d9 <4c> 8b 6b 40 4c 8b 23 4d 85 ed 74 12 49 8b bc 24 38 01 00 00 48 85
Jun 14 18:57:45 pve2 kernel: [173638.392779] RSP: 0018:ffffbade2e657b30 EFLAGS: 00010206
Jun 14 18:57:45 pve2 kernel: [173638.393507] RAX: 0000000000040000 RBX: 0000000040000000 RCX: 0000000000000018
Jun 14 18:57:45 pve2 kernel: [173638.394158] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff9abfb14ec3c0
Jun 14 18:57:45 pve2 kernel: [173638.394836] RBP: ffffbade2e657b58 R08: 0000000000000001 R09: 0000000000000001
Jun 14 18:57:45 pve2 kernel: [173638.395554] R10: 0000000000000001 R11: ffff9abec23c2270 R12: ffffffffc0f17b40
Jun 14 18:57:45 pve2 kernel: [173638.396189] R13: 0000000000000001 R14: ffffffffc0f17bc8 R15: 0000000000000001
Jun 14 18:57:45 pve2 kernel: [173638.396864] FS:  0000000000000000(0000) GS:ffff9acabed80000(0000) knlGS:0000000000000000
Jun 14 18:57:45 pve2 kernel: [173638.397512] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 14 18:57:45 pve2 kernel: [173638.398148] CR2: 0000000040000040 CR3: 000000026400c000 CR4: 00000000003506e0
Jun 15 06:39:26 pve2 kernel: [30933.304312] BUG: unable to handle page fault for address: 0000000040000034
Jun 15 06:39:26 pve2 kernel: [30933.304349] #PF: supervisor read access in kernel mode
Jun 15 06:39:26 pve2 kernel: [30933.304369] #PF: error_code(0x0000) - not-present page
Jun 15 06:39:26 pve2 kernel: [30933.304387] PGD 0 P4D 0 
Jun 15 06:39:26 pve2 kernel: [30933.304399] Oops: 0000 [#1] SMP NOPTI
Jun 15 06:39:26 pve2 kernel: [30933.304414] CPU: 10 PID: 624 Comm: arc_evict Tainted: P           O      5.15.30-2-pve #1
Jun 15 06:39:26 pve2 kernel: [30933.304442] Hardware name: Micro-Star International Co., Ltd MS-7B86/B450 GAMING PLUS MAX (MS-7B86), BIOS H.G0 07/26/2022
Jun 15 06:39:26 pve2 kernel: [30933.304476] RIP: 0010:__mutex_lock.constprop.0+0xb4/0x480
Jun 15 06:39:26 pve2 kernel: [30933.304500] Code: c4 40 5b 41 5c 41 5d 41 5e 41 5f 5d c3 65 48 8b 04 25 c0 fb 01 00 48 8b 00 a8 08 75 1d 49 8b 06 48 83 e0 f8 0f 84 ef 02 00 00 <8b> 50 34 85 d2 0f 85 d2 02 00 00 e8 bc 9b 41 ff 65 48 8b 04 25 c0
Jun 15 06:39:26 pve2 kernel: [30933.304557] RSP: 0018:ffffa90241263c90 EFLAGS: 00010206
Jun 15 06:39:26 pve2 kernel: [30933.304576] RAX: 0000000040000000 RBX: 000000000000062c RCX: ffff8dd14503b100
Jun 15 06:39:26 pve2 kernel: [30933.304598] RDX: ffff8dd14503b100 RSI: 0000000040000000 RDI: ffff8dd5326b9d20
Jun 15 06:39:26 pve2 kernel: [30933.304619] RBP: ffffa90241263cf8 R08: 9ae16a3b2f90408f R09: 9ae16a3b2f90404f
Jun 15 06:39:26 pve2 kernel: [30933.304641] R10: 0000000000000001 R11: ffff8dd523e9a3c0 R12: ffff8dd5326b9d20
Jun 15 06:39:26 pve2 kernel: [30933.304663] R13: 0000000000008000 R14: ffff8dd5326b9d20 R15: ffff8dd14af41e00
Jun 15 06:39:26 pve2 kernel: [30933.304685] FS:  0000000000000000(0000) GS:ffff8de03ec80000(0000) knlGS:0000000000000000
Jun 15 06:39:26 pve2 kernel: [30933.304710] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 15 06:39:26 pve2 kernel: [30933.304728] CR2: 0000000040000034 CR3: 000000026abb4000 CR4: 00000000003506e0
Jun 15 06:39:26 pve2 kernel: [30933.304750] Call Trace:
Jun 15 06:39:26 pve2 kernel: [30933.304760]  <TASK>
Jun 15 06:39:26 pve2 kernel: [30933.304767]  ? kmem_cache_free+0x26e/0x290
Jun 15 06:39:26 pve2 kernel: [30933.304789]  ? arc_state_multilist_index_func+0x2e/0x40 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.304885]  __mutex_lock_slowpath+0x13/0x20
Jun 15 06:39:26 pve2 kernel: [30933.304901]  mutex_lock+0x34/0x40
Jun 15 06:39:26 pve2 kernel: [30933.304913]  arc_hdr_destroy+0xda/0x200 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.304985]  arc_evict_state+0x61f/0xa40 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.305058]  arc_evict_cb+0x8dc/0xf10 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.305129]  ? sigprocmask+0xa8/0xe0
Jun 15 06:39:26 pve2 kernel: [30933.305145]  zthr_procedure+0x13e/0x160 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.305247]  ? zrl_is_locked+0x20/0x20 [zfs]
Jun 15 06:39:26 pve2 kernel: [30933.305348]  thread_generic_wrapper+0x61/0x70 [spl]
Jun 15 06:39:26 pve2 kernel: [30933.305372]  ? __thread_exit+0x20/0x20 [spl]
Jun 15 06:39:26 pve2 kernel: [30933.305394]  kthread+0x127/0x150
Jun 15 06:39:26 pve2 kernel: [30933.305409]  ? set_kthread_struct+0x50/0x50
Jun 15 06:39:26 pve2 kernel: [30933.305424]  ret_from_fork+0x1f/0x30
Jun 15 06:39:26 pve2 kernel: [30933.305439]  </TASK>
Jun 15 06:39:26 pve2 kernel: [30933.306069] Modules linked in: ebtable_filter ebtables ip_set ip6table_raw iptable_raw ip6table_filter ip6_tables iptable_filter bpfilter nf_tables bonding tls softdog nfnetlink_log nfnetlink intel_rapl_msr intel_rapl_common edac_mce_amd snd_hda_codec_realtek snd_hda_codec_generic kvm_amd ledtrig_audio nouveau kvm snd_hda_codec_hdmi crct10dif_pclmul ghash_clmulni_intel mxm_wmi video aesni_intel drm_ttm_helper ttm snd_hda_intel crypto_simd snd_intel_dspcfg zram drm_kms_helper cryptd ppdev snd_intel_sdw_acpi rapl snd_hda_codec cec wmi_bmof snd_hda_core rc_core snd_hwdep i2c_algo_bit pcspkr snd_pcm efi_pstore fb_sys_fops syscopyarea snd_timer sysfillrect snd sysimgblt soundcore ccp k10temp parport_pc zfs(PO) parport mac_hid zunicode(PO) zzstd(O) zlua(O) zavl(PO) icp(PO) zcommon(PO) znvpair(PO) spl(O) vhost_net vhost vhost_iotlb tap ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi nct6775 hwmon_vid vfio_pci vfio_pci_core vfio_virqfd irqbypass
Jun 15 06:39:26 pve2 kernel: [30933.306135]  vfio_iommu_type1 vfio drm sunrpc ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear simplefb crc32_pclmul i2c_piix4 xhci_pci r8169 xhci_pci_renesas realtek ahci xhci_hcd libahci wmi gpio_amdpt gpio_generic
Jun 15 06:39:26 pve2 kernel: [30933.315016] CR2: 0000000040000034
Jun 15 06:39:26 pve2 kernel: [30933.315968] ---[ end trace 6ecff17a335a1f27 ]---
Jun 15 06:39:26 pve2 kernel: [30933.349619] RIP: 0010:__mutex_lock.constprop.0+0xb4/0x480
Jun 15 06:39:26 pve2 kernel: [30933.350267] Code: c4 40 5b 41 5c 41 5d 41 5e 41 5f 5d c3 65 48 8b 04 25 c0 fb 01 00 48 8b 00 a8 08 75 1d 49 8b 06 48 83 e0 f8 0f 84 ef 02 00 00 <8b> 50 34 85 d2 0f 85 d2 02 00 00 e8 bc 9b 41 ff 65 48 8b 04 25 c0
Jun 15 06:39:26 pve2 kernel: [30933.351535] RSP: 0018:ffffa90241263c90 EFLAGS: 00010206
Jun 15 06:39:26 pve2 kernel: [30933.352157] RAX: 0000000040000000 RBX: 000000000000062c RCX: ffff8dd14503b100
Jun 15 06:39:26 pve2 kernel: [30933.352797] RDX: ffff8dd14503b100 RSI: 0000000040000000 RDI: ffff8dd5326b9d20
Jun 15 06:39:26 pve2 kernel: [30933.353447] RBP: ffffa90241263cf8 R08: 9ae16a3b2f90408f R09: 9ae16a3b2f90404f
Jun 15 06:39:26 pve2 kernel: [30933.354087] R10: 0000000000000001 R11: ffff8dd523e9a3c0 R12: ffff8dd5326b9d20
Jun 15 06:39:26 pve2 kernel: [30933.354682] R13: 0000000000008000 R14: ffff8dd5326b9d20 R15: ffff8dd14af41e00
Jun 15 06:39:26 pve2 kernel: [30933.355270] FS:  0000000000000000(0000) GS:ffff8de03ec80000(0000) knlGS:0000000000000000
Jun 15 06:39:26 pve2 kernel: [30933.355872] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 15 06:39:26 pve2 kernel: [30933.356509] CR2: 0000000040000034 CR3: 000000026abb4000 CR4: 00000000003506e0

What are the properties on the dataset(s) in use here? Is native encryption in use? How about dedup?

Because at least one of these smells suspiciously like #11679 to me...

cainiaocome commented 1 year ago

@rincebrain thanks for inline the logs.

Though I don't feel like my issue is similar to the one you linked.

I don't think encryption is on. How do I check that? I am also not sure about dedup.

I used following command to create the zpool: zpool create -f -o ashift=12 hdpool raidz1 /dev/disk/by-id/ata-ST2000DM001-1ER164_W8E0F1LV /dev/disk/by-id/ata-TOSHIBA_HDWD130_50QVXDNAS

I did enable compression some time ago: zfs set compression=lz4 hdpool. So some datasets(virtual machine disks) are compressed, some are not.

More info:

➜  ~ zpool get all
NAME    PROPERTY                       VALUE                          SOURCE
hdpool  size                           3.62T                          -
hdpool  capacity                       15%                            -
hdpool  altroot                        -                              default
hdpool  health                         ONLINE                         -
hdpool  guid                           1281422363561899185            -
hdpool  version                        -                              default
hdpool  bootfs                         -                              default
hdpool  delegation                     on                             default
hdpool  autoreplace                    off                            default
hdpool  cachefile                      -                              default
hdpool  failmode                       wait                           default
hdpool  listsnapshots                  off                            default
hdpool  autoexpand                     off                            default
hdpool  dedupratio                     1.00x                          -
hdpool  free                           3.07T                          -
hdpool  allocated                      569G                           -
hdpool  readonly                       off                            -
hdpool  ashift                         12                             local
hdpool  comment                        -                              default
hdpool  expandsize                     -                              -
hdpool  freeing                        0                              -
hdpool  fragmentation                  18%                            -
hdpool  leaked                         0                              -
hdpool  multihost                      off                            default
hdpool  checkpoint                     -                              -
hdpool  load_guid                      12895454564760644781           -
hdpool  autotrim                       off                            default
hdpool  compatibility                  off                            default
hdpool  feature@async_destroy          enabled                        local
hdpool  feature@empty_bpobj            active                         local
hdpool  feature@lz4_compress           active                         local
hdpool  feature@multi_vdev_crash_dump  enabled                        local
hdpool  feature@spacemap_histogram     active                         local
hdpool  feature@enabled_txg            active                         local
hdpool  feature@hole_birth             active                         local
hdpool  feature@extensible_dataset     active                         local
hdpool  feature@embedded_data          active                         local
hdpool  feature@bookmarks              enabled                        local
hdpool  feature@filesystem_limits      enabled                        local
hdpool  feature@large_blocks           enabled                        local
hdpool  feature@large_dnode            enabled                        local
hdpool  feature@sha512                 enabled                        local
hdpool  feature@skein                  enabled                        local
hdpool  feature@edonr                  enabled                        local
hdpool  feature@userobj_accounting     active                         local
hdpool  feature@encryption             enabled                        local
hdpool  feature@project_quota          active                         local
hdpool  feature@device_removal         enabled                        local
hdpool  feature@obsolete_counts        enabled                        local
hdpool  feature@zpool_checkpoint       enabled                        local
hdpool  feature@spacemap_v2            active                         local
hdpool  feature@allocation_classes     enabled                        local
hdpool  feature@resilver_defer         enabled                        local
hdpool  feature@bookmark_v2            enabled                        local
hdpool  feature@redaction_bookmarks    enabled                        local
hdpool  feature@redacted_datasets      enabled                        local
hdpool  feature@bookmark_written       enabled                        local
hdpool  feature@log_spacemap           active                         local
hdpool  feature@livelist               enabled                        local
hdpool  feature@device_rebuild         enabled                        local
hdpool  feature@zstd_compress          enabled                        local
hdpool  feature@draid                  enabled                        local
➜  ~
rincebrain commented 1 year ago

zfs get all [dataset] will tell you the properties of that, though since the pool-wide encryption feature flag is "enabled" and not "active", almost certainly not.

cainiaocome commented 1 year ago

After multiple tests with different configurations, I came to conclusion(it may be wrong, I only have access to three home lab environments):

It's not zfs causing these crashes, or at least on its own. It's more probably KSM.

After I disabled KSM, I haven't seen crashes above for more than two weeks already. Before that the system crashes in 1 to 4 days.

I doubt that KSM, swap, zfs together is not stable.

If anybody come to here and you have following setup and workloads like mine, try disable KSM and check whether your system still crashes:

  1. Proxmox as hypervisor
  2. KSM enabled(default in proxmox)
  3. swap enabled(default in proxmox?)
  4. zfs in use
  5. virtual machines use a lot of ram which leads the system to use swap
  6. virtual machines rewrite ram content constantly, start and stop new processes constantly
  7. swap in and swap out happens a lot
rincebrain commented 1 year ago

I would still consider it a bug if KSM is causing us to break things, unless there's some reason to believe it's a bug in KSM itself.