cifsd-team / ksmbd

ksmbd kernel server(SMB/CIFS server)
151 stars 23 forks source link

[kernal crash] ksmbd: Failed to send message: -32 kernel NULL pointer dereference #561

Open jmandawg opened 2 years ago

jmandawg commented 2 years ago

Hey, i'm running Archlinux (Kernel version: 5.18.2-arch1-1), and ksmbd to serve files to my other computers. Recently I will hear the fans start running full speed and X is unresponsive. When i look at dmesg i see this error and the system is semi-crashed, i'm going to switch back to samba and see if the problem resolves:

[11099.464495] usb 1-2.1: USB disconnect, device number 4
[11099.464503] usb 1-2.1.1: USB disconnect, device number 6
[11099.879428] usb 1-2.1.3: USB disconnect, device number 10
[18013.557728] [drm] DP Alt mode state on HPD: 1
[21888.639360] [drm] DP Alt mode state on HPD: 1
[32254.853120] [drm] DP Alt mode state on HPD: 1
[37054.109552] perf: interrupt took too long (2506 > 2500), lowering kernel.perf_event_max_sample_rate to 79800
[38906.599660] BUG: kernel NULL pointer dereference, address: 0000000000000015
[38906.599664] #PF: supervisor read access in kernel mode
[38906.599665] #PF: error_code(0x0000) - not-present page
[38906.599666] PGD 0 P4D 0
[38906.599668] Oops: 0000 [#1] PREEMPT SMP NOPTI
[38906.599669] CPU: 10 PID: 13263 Comm: kworker/10:1 Not tainted 5.18.2-arch1-1 #1 3d71b353df58e0aa4fcdc1730c70c1a91e7876b0
[38906.599672] Hardware name: SYSTEM_MANUFACTURER HX90/HX90, BIOS 5.19 10/11/2021
[38906.599673] Workqueue: ksmbd-io handle_ksmbd_work [ksmbd]
[38906.599683] RIP: 0010:smb2_open+0x112f/0x21d0 [ksmbd]
[38906.599692] Code: 7c 24 5b 00 0f 85 11 09 00 00 48 8d 94 24 a0 00 00 00 31 c0 b9 0e 00 00 00 48 89 d7 f3 ab 49 8b 43 20 83 60 60 f9 49 8b 46 08 <f6> 40 14 40 74 57 48 8b 84 24 90 00 00 00 4c 89 5c 24 48 44 89 44
[38906.599693] RSP: 0018:ffffaed3c4c7bcb8 EFLAGS: 00010202
[38906.599694] RAX: 0000000000000001 RBX: ffff9a69d7849740 RCX: 0000000000000000
[38906.599695] RDX: ffffaed3c4c7bd58 RSI: 0000000000000000 RDI: ffffaed3c4c7bd90
[38906.599696] RBP: ffff9a69fb95ce04 R08: 0000000000000000 R09: 0000000000000018
[38906.599696] R10: 00000000efe4b900 R11: ffff9a69d7ec3b80 R12: ffff9a69d8218000
[38906.599697] R13: 0000000000000009 R14: ffff9a69463dee00 R15: ffff9a697bed0c00
[38906.599698] FS:  0000000000000000(0000) GS:ffff9a702e880000(0000) knlGS:0000000000000000
[38906.599699] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38906.599699] CR2: 0000000000000015 CR3: 00000007ad810000 CR4: 0000000000750ee0
[38906.599700] PKRU: 55555554
[38906.599701] Call Trace:
[38906.599702]  <TASK>
[38906.599705]  handle_ksmbd_work+0x147/0x3c0 [ksmbd ecd4837d804935c288b2b49ba8720c457310c578]
[38906.599713]  process_one_work+0x1c4/0x380
[38906.599716]  worker_thread+0x51/0x380
[38906.599717]  ? rescuer_thread+0x3a0/0x3a0
[38906.599718]  kthread+0xdb/0x110
[38906.599720]  ? kthread_complete_and_exit+0x20/0x20
[38906.599721]  ret_from_fork+0x1f/0x30
[38906.599724]  </TASK>
[38906.599725] Modules linked in: rfcomm nls_utf8 iptable_nat wireguard curve25519_x86_64 libchacha20poly1305 chacha_x86_64 poly1305_x86_64 libcurve25519_generic libchacha ip6_udp_tunnel udp_tunnel vhost_net tun vhost vhost_iotlb macvtap macvlan tap xt_nat xt_tcpudp veth xt_conntrack nft_chain_nat xt_MASQUERADE nf_nat nf_conntrack_netlink nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_addrtype nft_compat nf_tables libcrc32c nfnetlink br_netfilter bridge overlay ksmbd crc32_generic rdma_cm joydev mousedev iw_cm ib_cm hid_holtek_mouse ib_core cifs_arc4 cmac algif_hash 8021q garp algif_skcipher mrp af_alg stp llc bnep uas usb_storage ax88179_178a usbnet mii snd_sof_amd_renoir snd_sof_amd_acp intel_rapl_msr snd_sof_pci intel_rapl_common hid_cmedia snd_sof snd_usb_audio btusb snd_sof_utils snd_usbmidi_lib btrtl ledtrig_audio iwlmvm snd_rawmidi btbcm snd_soc_core edac_mce_amd btintel snd_seq_device mc usbhid btmtk snd_compress mac80211 bluetooth kvm_amd libarc4 ac97_bus ecdh_generic
[38906.599756]  snd_hda_codec_hdmi snd_pcm_dmaengine kvm snd_hda_intel iwlwifi snd_intel_dspcfg snd_intel_sdw_acpi vfat iwlmei fat snd_hda_codec irqbypass snd_acp_pci wmi_bmof crct10dif_pclmul snd_pci_acp6x snd_hda_core crc32_pclmul snd_hwdep ghash_clmulni_intel cfg80211 snd_pci_acp5x snd_pcm aesni_intel snd_rn_pci_acp3x snd_timer rfkill crypto_simd sp5100_tco snd snd_acp_config cryptd mei igc snd_soc_acpi tpm_crb rapl soundcore i2c_piix4 pcspkr snd_pci_acp3x ccp k10temp amd_sfh tpm_tis wmi cm32181 tpm_tis_core video tpm acpi_cpufreq industrialio i2c_hid_acpi rng_core mac_hid i2c_hid pinctrl_amd dm_multipath dm_mod crypto_user fuse bpf_preload ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 nvme xhci_pci crc32c_intel nvme_core xhci_pci_renesas radeon amdgpu gpu_sched drm_ttm_helper ttm drm_dp_helper
[38906.599785] CR2: 0000000000000015
[38906.599786] ---[ end trace 0000000000000000 ]---
[38906.599786] RIP: 0010:smb2_open+0x112f/0x21d0 [ksmbd]
[38906.599794] Code: 7c 24 5b 00 0f 85 11 09 00 00 48 8d 94 24 a0 00 00 00 31 c0 b9 0e 00 00 00 48 89 d7 f3 ab 49 8b 43 20 83 60 60 f9 49 8b 46 08 <f6> 40 14 40 74 57 48 8b 84 24 90 00 00 00 4c 89 5c 24 48 44 89 44
[38906.599795] RSP: 0018:ffffaed3c4c7bcb8 EFLAGS: 00010202
[38906.599795] RAX: 0000000000000001 RBX: ffff9a69d7849740 RCX: 0000000000000000
[38906.599796] RDX: ffffaed3c4c7bd58 RSI: 0000000000000000 RDI: ffffaed3c4c7bd90
[38906.599797] RBP: ffff9a69fb95ce04 R08: 0000000000000000 R09: 0000000000000018
[38906.599797] R10: 00000000efe4b900 R11: ffff9a69d7ec3b80 R12: ffff9a69d8218000
[38906.599798] R13: 0000000000000009 R14: ffff9a69463dee00 R15: ffff9a697bed0c00
[38906.599799] FS:  0000000000000000(0000) GS:ffff9a702e880000(0000) knlGS:0000000000000000
[38906.599799] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38906.599800] CR2: 0000000000000015 CR3: 00000007ad810000 CR4: 0000000000750ee0
[38906.599801] PKRU: 55555554
[38906.600306] ksmbd: Failed to send message: -32
[38906.600310] BUG: kernel NULL pointer dereference, address: 0000000000000015
[38906.600314] #PF: supervisor read access in kernel mode
[38906.600316] #PF: error_code(0x0000) - not-present page
[38906.600317] PGD 0 P4D 0
[38906.600319] Oops: 0000 [#2] PREEMPT SMP NOPTI
[38906.600320] CPU: 14 PID: 13119 Comm: kworker/14:4 Tainted: G      D           5.18.2-arch1-1 #1 3d71b353df58e0aa4fcdc1730c70c1a91e7876b0
[38906.600323] Hardware name: SYSTEM_MANUFACTURER HX90/HX90, BIOS 5.19 10/11/2021
[38906.600324] Workqueue: ksmbd-io handle_ksmbd_work [ksmbd]
[38906.600347] ksmbd: Failed to send message: -32
[38906.600341] RIP: 0010:smb2_open+0x112f/0x21d0 [ksmbd]
[38906.600353] Code: 7c 24 5b 00 0f 85 11 09 00 00 48 8d 94 24 a0 00 00 00 31 c0 b9 0e 00 00 00 48 89 d7 f3 ab 49 8b 43 20 83 60 60 f9 49 8b 46 08 <f6> 40 14 40 74 57 48 8b 84 24 90 00 00 00 4c 89 5c 24 48 44 89 44
[38906.600354] RSP: 0018:ffffaed3c641bcb8 EFLAGS: 00010202
[38906.600355] RAX: 0000000000000001 RBX: ffff9a69483010e0 RCX: 0000000000000000
[38906.600356] RDX: ffffaed3c641bd58 RSI: 0000000000000000 RDI: ffffaed3c641bd90
[38906.600357] RBP: ffff9a6a24e9c404 R08: 0000000000000000 R09: 0000000000000018
[38906.600358] R10: 0000000001f15400 R11: ffff9a6997e0de00 R12: ffff9a694f227a00
[38906.600358] R13: 0000000000000009 R14: ffff9a69463dee00 R15: ffff9a697bed0c00
[38906.600359] FS:  0000000000000000(0000) GS:ffff9a702e980000(0000) knlGS:0000000000000000
[38906.600361] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38906.600361] CR2: 0000000000000015 CR3: 00000007ad810000 CR4: 0000000000750ee0
[38906.600362] PKRU: 55555554
[38906.600363] Call Trace:
[38906.600365]  <TASK>
[38906.600370]  handle_ksmbd_work+0x147/0x3c0 [ksmbd ecd4837d804935c288b2b49ba8720c457310c578]
[38906.600381]  process_one_work+0x1c4/0x380
[38906.600383]  worker_thread+0x51/0x380
[38906.600385]  ? rescuer_thread+0x3a0/0x3a0
[38906.600386]  kthread+0xdb/0x110
[38906.600388]  ? kthread_complete_and_exit+0x20/0x20
[38906.600390]  ret_from_fork+0x1f/0x30
[38906.600392]  </TASK>
[38906.600393] Modules linked in: rfcomm nls_utf8 iptable_nat wireguard curve25519_x86_64 libchacha20poly1305 chacha_x86_64 poly1305_x86_64 libcurve25519_generic libchacha ip6_udp_tunnel udp_tunnel vhost_net tun vhost vhost_iotlb macvtap macvlan tap xt_nat xt_tcpudp veth xt_conntrack nft_chain_nat xt_MASQUERADE nf_nat nf_conntrack_netlink nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_addrtype nft_compat nf_tables libcrc32c nfnetlink br_netfilter bridge overlay ksmbd crc32_generic rdma_cm joydev mousedev iw_cm ib_cm hid_holtek_mouse ib_core cifs_arc4 cmac algif_hash 8021q garp algif_skcipher mrp af_alg stp llc bnep uas usb_storage ax88179_178a usbnet mii snd_sof_amd_renoir snd_sof_amd_acp intel_rapl_msr snd_sof_pci intel_rapl_common hid_cmedia snd_sof snd_usb_audio btusb snd_sof_utils snd_usbmidi_lib btrtl ledtrig_audio iwlmvm snd_rawmidi btbcm snd_soc_core edac_mce_amd btintel snd_seq_device mc usbhid btmtk snd_compress mac80211 bluetooth kvm_amd libarc4 ac97_bus ecdh_generic
[38906.600433]  snd_hda_codec_hdmi snd_pcm_dmaengine kvm snd_hda_intel iwlwifi snd_intel_dspcfg snd_intel_sdw_acpi vfat iwlmei fat snd_hda_codec irqbypass snd_acp_pci wmi_bmof crct10dif_pclmul snd_pci_acp6x snd_hda_core crc32_pclmul snd_hwdep ghash_clmulni_intel cfg80211 snd_pci_acp5x snd_pcm aesni_intel snd_rn_pci_acp3x snd_timer rfkill crypto_simd sp5100_tco snd snd_acp_config cryptd mei igc snd_soc_acpi tpm_crb rapl soundcore i2c_piix4 pcspkr snd_pci_acp3x ccp k10temp amd_sfh tpm_tis wmi cm32181 tpm_tis_core video tpm acpi_cpufreq industrialio i2c_hid_acpi rng_core mac_hid i2c_hid pinctrl_amd dm_multipath dm_mod crypto_user fuse bpf_preload ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 nvme xhci_pci crc32c_intel nvme_core xhci_pci_renesas radeon amdgpu gpu_sched drm_ttm_helper ttm drm_dp_helper
[38906.600463] CR2: 0000000000000015
[38906.600464] ---[ end trace 0000000000000000 ]---
[38906.600465] RIP: 0010:smb2_open+0x112f/0x21d0 [ksmbd]
[38906.600474] Code: 7c 24 5b 00 0f 85 11 09 00 00 48 8d 94 24 a0 00 00 00 31 c0 b9 0e 00 00 00 48 89 d7 f3 ab 49 8b 43 20 83 60 60 f9 49 8b 46 08 <f6> 40 14 40 74 57 48 8b 84 24 90 00 00 00 4c 89 5c 24 48 44 89 44
[38906.600475] RSP: 0018:ffffaed3c4c7bcb8 EFLAGS: 00010202
[38906.600476] RAX: 0000000000000001 RBX: ffff9a69d7849740 RCX: 0000000000000000
[38906.600477] RDX: ffffaed3c4c7bd58 RSI: 0000000000000000 RDI: ffffaed3c4c7bd90
[38906.600478] RBP: ffff9a69fb95ce04 R08: 0000000000000000 R09: 0000000000000018
[38906.600479] R10: 00000000efe4b900 R11: ffff9a69d7ec3b80 R12: ffff9a69d8218000
[38906.600479] R13: 0000000000000009 R14: ffff9a69463dee00 R15: ffff9a697bed0c00
[38906.600480] FS:  0000000000000000(0000) GS:ffff9a702e980000(0000) knlGS:0000000000000000
[38906.600481] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[38906.600482] CR2: 0000000000000015 CR3: 00000007ad810000 CR4: 0000000000750ee0
[38906.600483] PKRU: 55555554
[41308.836258] perf: interrupt took too long (3141 > 3132), lowering kernel.perf_event_max_sample_rate to 63600
[42173.159367] ksmbd: Failed to send message: -32
[44791.300179] [drm] DP Alt mode state on HPD: 1
[44792.462420] usb 1-2.1: new high-speed USB device number 11 using xhci_hcd
[44792.606456] usb 1-2.1: New USB device found, idVendor=05e3, idProduct=0610, bcdDevice=92.23
[44792.606459] usb 1-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[44792.606462] usb 1-2.1: Product: USB2.0 Hub
[44792.606463] usb 1-2.1: Manufacturer: GenesysLogic
[44792.670116] hub 1-2.1:1.0: USB hub found
[44792.670832] hub 1-2.1:1.0: 4 ports detected
[44832.019435] audit: type=1100 audit(1654907124.349:203): pid=14783 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:authentication grantors=pam_shells,pam_faillock,pam_permit,pam_faillock acct="jmoon" exe="/usr/bin/sshd" hostname=192.168.16.13 addr=192.168.16.13 terminal=ssh res=success'
[44832.024586] audit: type=1101 audit(1654907124.352:204): pid=14783 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="jmoon" exe="/usr/bin/sshd" hostname=192.168.16.13 addr=192.168.16.13 terminal=ssh res=success'
[44832.025082] audit: type=1103 audit(1654907124.352:205): pid=14783 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:setcred grantors=pam_shells,pam_faillock,pam_permit,pam_faillock acct="jmoon" exe="/usr/bin/sshd" hostname=192.168.16.13 addr=192.168.16.13 terminal=ssh res=success'
[44832.025123] audit: type=1006 audit(1654907124.352:206): pid=14783 uid=0 old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=3 res=1
[44832.025127] audit: type=1300 audit(1654907124.352:206): arch=c000003e syscall=1 success=yes exit=4 a0=3 a1=7ffd97ecf160 a2=4 a3=7ffd97ecee74 items=0 ppid=569 pid=14783 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=3 comm="sshd" exe="/usr/bin/sshd" key=(null)
[44832.025130] audit: type=1327 audit(1654907124.352:206): proctitle=737368643A206A6D6F6F6E205B707269765D
[44832.061317] audit: type=1105 audit(1654907124.389:207): pid=14783 uid=0 auid=1000 ses=3 msg='op=PAM:session_open grantors=pam_loginuid,pam_keyinit,pam_systemd_home,pam_limits,pam_unix,pam_permit,pam_mail,pam_systemd,pam_env acct="jmoon" exe="/usr/bin/sshd" hostname=192.168.16.13 addr=192.168.16.13 terminal=ssh res=success'
[44832.062078] audit: type=1103 audit(1654907124.389:208): pid=14786 uid=0 auid=1000 ses=3 msg='op=PAM:setcred grantors=pam_shells,pam_faillock,pam_permit,pam_faillock acct="jmoon" exe="/usr/bin/sshd" hostname=192.168.16.13 addr=192.168.16.13 terminal=ssh res=success'
[44915.209565] audit: type=1101 audit(1654907207.539:209): pid=14806 uid=1000 auid=1000 ses=3 msg='op=PAM:accounting grantors=pam_unix,pam_permit,pam_time acct="jmoon" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/2 res=success'
[44915.209985] audit: type=1110 audit(1654907207.539:210): pid=14806 uid=1000 auid=1000 ses=3 msg='op=PAM:setcred grantors=pam_faillock,pam_permit,pam_env,pam_faillock acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/2 res=success'
[44915.210052] audit: type=1105 audit(1654907207.539:211): pid=14806 uid=1000 auid=1000 ses=3 msg='op=PAM:session_open grantors=pam_systemd_home,pam_limits,pam_unix,pam_permit acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/2 res=success'
namjaejeon commented 2 years ago

share directory is located in usb storage ?

jmandawg commented 2 years ago

Yes it is a USB drive. I believe the USB disconnect is me switching the keyboard and mouse to my other computer via a 4 port USB hub connected to a USB selector switch.

namjaejeon commented 2 years ago

Okay, I just can check problem is happening in smb2_open(). Don't know what line cause kernel oops at smb2_open(). So trying to reproduce it. Can you tell me some info of your environment ?

  1. What local filesystem in usb storage do you used ?
  2. dump your smb.conf contents here.
  3. Can you tell me what operation is being performed in ksmbd? e.g. copy files to ksmbd share ?
namjaejeon commented 2 years ago

But I can see usb is connected again under usb disconnect message.

[44792.462420] usb 1-2.1: new high-speed USB device number 11 using xhci_hcd
[44792.606456] usb 1-2.1: New USB device found, idVendor=05e3, idProduct=0610, bcdDevice=92.23
[44792.606459] usb 1-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[44792.606462] usb 1-2.1: Product: USB2.0 Hub
[44792.606463] usb 1-2.1: Manufacturer: GenesysLogic
[44792.670116] hub 1-2.1:1.0: USB hub found
[44792.670832] hub 1-2.1:1.0: 4 ports detected

So Is it true that USB storage is unplugged ?

jmandawg commented 2 years ago
  1. What local filesystem in usb storage do you used ? ext4
  2. dump your smb.conf contents here.
    
    [global]
    server = delli5
    netbios name = delli5
    map to guest = Bad User
    guest account = nobody

[root] comment = root file system path = / writable = yes browseable = no read only = no hide dot files = no guest ok = no valid users = jman create mask = 0777 directory mask = 02777 force user = jman force group = jman

[media] comment = 4TB Media path = /mnt/8TB-seagate/media read only = no writable = yes hide dot files = no guest ok = yes create mask = 0777 directory mask = 02777 force user = jman force group = jman


3. Can you tell me what operation is being performed in ksmbd? e.g. copy files to ksmbd share ?
I'm not sure, because it just randomly happens.  Sometimes just wake up and it is crashed in the morning.

4. So Is it true that USB storage is unplugged ?
No, usb drive is never unplugged.  Only the hub with keyboard/mouse is switched to other computer.