cifsd-team / ksmbd

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

RDMA crash #609

Closed heppu closed 9 months ago

heppu commented 10 months ago

OS: Voidlinux Kernel: 6.5.13_1 Adapter: Mellanox ConnectX-4

/etc/ksmbd/ksmbd.conf ; see ksmbd.conf(5) for details [global] server multi channel support = yes bind interfaces only = yes interfaces = ib1 [Games] ; share parameters ;force group = app ;force user = app path = /mnt/pool-0/games read only = no valid users = app writeable = yes guest ok = no

After following your instructions and compiling the kernel with Support for SMB Direct protocol and now I can see that RDMA listener is created but as soon as I open the connection I get the stack trace in dmesg.

dmesg output with debug logs and stacktrace ``` [ 514.591572] ksmbd: smb_direct: init RDMA listener. cm_id=00000000bee9a6a3 [ 591.236119] ksmbd: connect success: accepted new connection [ 591.236266] ksmbd: RFC1002 header 69 bytes [ 591.236285] ksmbd: client requested dialect \x02NT LM 0.12 [ 591.236288] ksmbd: client requested dialect \x02SMB 2.002 [ 591.236290] ksmbd: client requested dialect \x02SMB 2.??? [ 591.236292] ksmbd: selected \x02SMB 2.??? dialect [ 591.236294] ksmbd: conn->dialect 0x2ff [ 591.236297] ksmbd: conn->dialect 0x2ff [ 591.236300] ksmbd: Upgrade to SMB2 negotiation [ 591.236302] ksmbd: credits: requested[1] granted[1] total_granted[1] [ 591.236519] ksmbd: RFC1002 header 234 bytes [ 591.236534] ksmbd: no length check for command [ 591.236536] ksmbd: SMB2 data length 0 offset 0 [ 591.236538] ksmbd: SMB2 len 100 [ 591.236541] ksmbd: client requested dialect 0x311 [ 591.236543] ksmbd: selected \x02SMB 3.1.1 dialect [ 591.236545] ksmbd: conn->dialect 0x311 [ 591.236547] ksmbd: Received negotiate request [ 591.236549] ksmbd: decoding 4 negotiate contexts [ 591.236551] ksmbd: deassemble SMB2_PREAUTH_INTEGRITY_CAPABILITIES context [ 591.236553] ksmbd: deassemble SMB2_ENCRYPTION_CAPABILITIES context [ 591.236555] ksmbd: Cipher ID = 0x2 [ 591.236557] ksmbd: deassemble SMB2_COMPRESSION_CAPABILITIES context [ 591.236559] ksmbd: deassemble SMB2_NETNAME_NEGOTIATE_CONTEXT_ID context [ 591.236579] ksmbd: assemble SMB2_PREAUTH_INTEGRITY_CAPABILITIES context [ 591.236583] ksmbd: assemble SMB2_ENCRYPTION_CAPABILITIES context [ 591.236585] ksmbd: negotiate context offset 208, count 2 [ 591.236588] ksmbd: credits: requested[1] granted[1] total_granted[1] [ 591.237248] ksmbd: RFC1002 header 162 bytes [ 591.237261] ksmbd: SMB2 data length 74 offset 88 [ 591.237264] ksmbd: SMB2 len 162 [ 591.237267] ksmbd: Received request for session setup [ 591.237280] ksmbd: negotiate phase [ 591.237285] ksmbd: NTLMSSP SecurityBufferLength 188 [ 591.237289] ksmbd: credits: requested[33] granted[33] total_granted[33] [ 591.237702] ksmbd: RFC1002 header 546 bytes [ 591.237710] ksmbd: SMB2 data length 458 offset 88 [ 591.237712] ksmbd: SMB2 len 546 [ 591.237713] ksmbd: Received request for session setup [ 591.237718] ksmbd: authenticate phase [ 591.237720] ksmbd: session setup request for user app [ 591.238103] ksmbd: decode_ntlmssp_authenticate_blob dname. [ 591.245751] ksmbd: dumping generated AES encryption keys [ 591.245755] ksmbd: Cipher type 2 [ 591.245757] ksmbd: Session Id 1 [ 591.245759] ksmbd: Session Key 32 5a a4 37 a3 cc bd e9 cf 6c 7d ac 73 d9 e2 06 [ 591.245762] ksmbd: ServerIn Key 8b b0 e7 e8 8e 40 50 b0 9b 8d 0e 8a cf f5 af e6 [ 591.245764] ksmbd: ServerOut Key 6d e0 ef 1b 64 b5 08 16 b5 b5 39 6f 6b 00 3d 43 [ 591.245783] ksmbd: dumping generated AES signing keys [ 591.245785] ksmbd: Session Id 1 [ 591.245787] ksmbd: Session Key 32 5a a4 37 a3 cc bd e9 cf 6c 7d ac 73 d9 e2 06 [ 591.245789] ksmbd: Signing Key 46 9f f2 e6 8e 8c cb a6 68 08 69 33 4a ea 61 5d [ 591.245791] ksmbd: credits: requested[1] granted[1] total_granted[33] [ 591.248990] ksmbd: RFC1002 header 112 bytes [ 591.249004] ksmbd: skip to check tree connect request [ 591.249007] ksmbd: SMB2 data length 40 offset 72 [ 591.249009] ksmbd: SMB2 len 112 [ 591.249023] ksmbd: tree connect request for tree ipc$ treename \\192.168.255.1\IPC$ [ 591.249212] ksmbd: IPC share path request [ 591.249215] ksmbd: credits: requested[1] granted[1] total_granted[33] [ 591.249395] ksmbd: RFC1002 header 120 bytes [ 591.249555] ksmbd: SMB2 data length 0 offset 120 [ 591.249559] ksmbd: SMB2 len 121 [ 591.249596] ksmbd: RFC1002 header 164 bytes [ 591.249832] ksmbd: SMB2 data length 44 offset 120 [ 591.249835] ksmbd: SMB2 len 164 [ 591.249838] ksmbd: credits: requested[1] granted[1] total_granted[33] [ 591.250662] ksmbd: RFC1002 header 114 bytes [ 591.250669] ksmbd: skip to check tree connect request [ 591.250670] ksmbd: SMB2 data length 42 offset 72 [ 591.250672] ksmbd: SMB2 len 114 [ 591.250682] ksmbd: tree connect request for tree games treename \\192.168.255.1\games [ 591.250764] ksmbd: credits: requested[1] granted[1] total_granted[33] [ 591.250818] ------------[ cut here ]------------ [ 591.250820] memcpy: detected field-spanning write (size 44) of single field "eseg->inline_hdr.start" at drivers/infiniband/hw/mlx5/wr.c:81 (size 2) [ 591.250843] WARNING: CPU: 36 PID: 234 at drivers/infiniband/hw/mlx5/wr.c:81 mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.250862] Modules linked in: tcp_diag inet_diag ksmbd crc32_generic cifs_arc4 veth xt_nat xt_tcpudp xt_conntrack xt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_addrtype iptable_filter ip_tables x_tables br_netfilter bridge overlay cfg80211 nfsd 8021q nfs garp auth_rpcgss mrp netfs nfs_acl stp lockd llc fscache grace intel_rapl_msr intel_rapl_common amd64_edac edac_mce_amd kvm_amd kvm ipmi_ssif irqbypass eeepc_wmi asus_wmi battery ledtrig_audio sparse_keymap platform_profile video rapl acpi_cpufreq wmi_bmof pcspkr snd_usb_audio snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec snd_usbmidi_lib mlx5_ib snd_rawmidi snd_hda_core mc snd_hwdep ch341 ib_uverbs snd_pcm input_leds joydev usbserial acpi_ipmi k10temp i2c_piix4 ipmi_si ipmi_devintf evdev tpm_crb mac_hid ipmi_msghandler i2c_designware_platform tpm_tis i2c_designware_core tpm_tis_core tiny_power_button tpm rpcrdma rdma_cm configfs iw_cm ib_ipoib ib_cm ib_umad ib_core snd_seq [ 591.250949] snd_seq_device snd_timer snd soundcore vhost_vsock vmw_vsock_virtio_transport_common vsock vhost_net vhost vhost_iotlb tap hci_vhci bluetooth ecdh_generic rfkill ecc crc16 vfio_iommu_type1 vfio iommufd uhid dm_mod uinput userio ppp_generic slhc tun loop nvram btrfs blake2b_generic xor raid6_pq libcrc32c crc32c_generic cuse fuse crct10dif_pclmul crc32_pclmul crc32c_intel hid_multitouch hid_generic usbhid ghash_clmulni_intel sha512_ssse3 sha256_ssse3 sha1_ssse3 hid sd_mod aesni_intel crypto_simd cryptd mlx5_core mpt3sas ast i2c_algo_bit ahci xhci_pci drm_shmem_helper mlxfw xhci_pci_renesas libahci zfs(POE) drm_kms_helper raid_class mxm_wmi xhci_hcd libata psample scsi_transport_sas ccp drm spl(OE) pci_hyperv_intf ixgbe rng_core usbcore scsi_mod xfrm_algo agpgart dca scsi_common mdio sp5100_tco usb_common wmi button sunrpc [ 591.251032] CPU: 36 PID: 234 Comm: kworker/36:0 Tainted: P OE 6.5.13_1 #1 [ 591.251035] Hardware name: ASUS System Product Name/Pro WS WRX80E-SAGE SE WIFI, BIOS 1106 02/10/2023 [ 591.251037] Workqueue: ksmbd-io handle_ksmbd_work [ksmbd] [ 591.251057] RIP: 0010:mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.251072] Code: c6 48 c7 c2 48 07 dc c1 48 c7 c7 90 07 dc c1 48 89 44 24 48 4c 89 4c 24 10 4c 89 44 24 08 c6 05 36 bd 04 00 01 e8 a4 8e 37 cb <0f> 0b 8b 4c 24 58 4c 8b 74 24 70 4c 8b 6c 24 68 48 8b 44 24 48 4c [ 591.251073] RSP: 0018:ffffa565c0edf748 EFLAGS: 00010082 [ 591.251076] RAX: 0000000000000000 RBX: ffff98ec9daa6748 RCX: 0000000000000000 [ 591.251077] RDX: 0000000000000205 RSI: ffffffff8e2e0e8c RDI: 00000000ffffffff [ 591.251079] RBP: 0000000000000000 R08: 0000000000000000 R09: ffffa565c0edf5f0 [ 591.251080] R10: 0000000000000003 R11: ffff996b3ee978a8 R12: 0000000000000001 [ 591.251081] R13: ffffa565c5ba0000 R14: ffffa565c5b9f890 R15: ffff98ecae716000 [ 591.251083] FS: 0000000000000000(0000) GS:ffff996933700000(0000) knlGS:0000000000000000 [ 591.251085] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 591.251087] CR2: 000000c00062fff8 CR3: 0000000237602000 CR4: 0000000000350ee0 [ 591.251088] Call Trace: [ 591.251091] [ 591.251093] ? mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.251107] ? __warn+0x81/0x130 [ 591.251113] ? mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.251127] ? report_bug+0x191/0x1c0 [ 591.251132] ? handle_bug+0x41/0x70 [ 591.251135] ? exc_invalid_op+0x17/0x70 [ 591.251138] ? asm_exc_invalid_op+0x1a/0x20 [ 591.251143] ? mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.251158] ? mlx5_ib_post_send+0xe5c/0xf30 [mlx5_ib] [ 591.251176] ipoib_send+0x2ef/0x5d0 [ib_ipoib] [ 591.251189] ipoib_start_xmit+0x488/0x710 [ib_ipoib] [ 591.251198] ? srso_return_thunk+0x5/0x10 [ 591.251202] ? netif_skb_features+0x151/0x2e0 [ 591.251207] dev_hard_start_xmit+0x7b/0x1f0 [ 591.251211] sch_direct_xmit+0xa4/0x380 [ 591.251216] __dev_queue_xmit+0x4bf/0xdb0 [ 591.251219] ? srso_return_thunk+0x5/0x10 [ 591.251221] ? push_pseudo_header+0x13/0x30 [ib_ipoib] [ 591.251230] ? srso_return_thunk+0x5/0x10 [ 591.251232] ? ipoib_hard_header+0x37/0x50 [ib_ipoib] [ 591.251241] ? srso_return_thunk+0x5/0x10 [ 591.251245] ip_finish_output2+0x176/0x570 [ 591.251249] __ip_queue_xmit+0x175/0x460 [ 591.251252] ? srso_return_thunk+0x5/0x10 [ 591.251254] ? srso_return_thunk+0x5/0x10 [ 591.251256] ? preempt_count_add+0x6e/0xa0 [ 591.251260] __tcp_transmit_skb+0xac2/0xc10 [ 591.251268] tcp_write_xmit+0x54e/0x14d0 [ 591.251272] __tcp_push_pending_frames+0x36/0xf0 [ 591.251275] tcp_sendmsg_locked+0xb44/0xd20 [ 591.251282] tcp_sendmsg+0x2b/0x40 [ 591.251285] sock_sendmsg+0xb5/0x100 [ 591.251291] ? srso_return_thunk+0x5/0x10 [ 591.251293] ? srso_return_thunk+0x5/0x10 [ 591.251296] ? __wake_up_common_lock+0x8e/0xd0 [ 591.251300] ksmbd_tcp_writev+0x48/0x70 [ksmbd] [ 591.251321] ksmbd_conn_write+0xbd/0x1a0 [ksmbd] [ 591.251341] handle_ksmbd_work+0x270/0x470 [ksmbd] [ 591.251360] process_one_work+0x1e2/0x3e0 [ 591.251365] worker_thread+0x51/0x390 [ 591.251368] ? __pfx_worker_thread+0x10/0x10 [ 591.251370] kthread+0xf7/0x130 [ 591.251373] ? __pfx_kthread+0x10/0x10 [ 591.251376] ret_from_fork+0x34/0x50 [ 591.251380] ? __pfx_kthread+0x10/0x10 [ 591.251382] ret_from_fork_asm+0x1b/0x30 [ 591.251390] [ 591.251391] ---[ end trace 0000000000000000 ]--- [ 591.251508] ksmbd: credits: requested[1] granted[1] total_granted[33] [ 591.282277] ksmbd: RFC1002 header 248 bytes [ 591.282287] ksmbd: RFC1002 header 176 bytes [ 591.282307] ksmbd: SMB2 data length 104 offset 144 [ 591.282309] ksmbd: SMB2 len 248 [ 591.282314] ksmbd: converted name = Desktop.ini [ 591.282316] ksmbd: get query maximal access context [ 591.282500] ksmbd: can not get linux path for Desktop.ini, rc = -2 [ 591.282503] ksmbd: Error response: c0000034 [ 591.282505] ksmbd: credits: requested[1] granted[1] total_granted[33] ```

Also from the wireshark I can see that RSS and RDMA capabilities are set to 0 in FSCTL_QUERY_NETWORK_INTERFACE_INFO response. If more information is needed I can reproduce this issue every time.

heppu commented 10 months ago

Also tested that kernel version 6.6.3_1 has same issue.

namjaejeon commented 10 months ago

This is not ksmbd issue. the problem is coming from mlx5_ib_post_send() in mlx5 driver.

heppu commented 10 months ago

From the stack trace I can see that it originates from ksmbd:

[  591.251300]  ksmbd_tcp_writev+0x48/0x70 [ksmbd]
[  591.251321]  ksmbd_conn_write+0xbd/0x1a0 [ksmbd]

and also this doesn't happen with other RDMA applications so I was wondering could ksmbd some how cause this by accident?

namjaejeon commented 10 months ago

This is just warning, not BUG_ON trap. you can debug memcpy overrun buffer in mlx driver.

heppu commented 10 months ago

Do you think this is the cause for ksmdb reporting the interface not having RDMA and RSS capabilities? Any tips how to debug why that happens?

namjaejeon commented 10 months ago

https://www.spinics.net/lists/linux-rdma/msg117721.html

This is not caused by only ksmbd.

heppu commented 10 months ago

In that case I will be waiting for upstream fix in linux-rdma. Thanks for quick response and explanation!

namjaejeon commented 10 months ago

From: Chuck Lever III chuck.lever@xxxxxxxxxx Date: Tue, 6 Jun 2023 13:49:07 +0000

Chuck is NFSD maintainer, and he reported it on Tue, 6 Jun 2023. i.e. quite a long time ago. I think that you need to report it linux-rdma mailing list and mlx5 driver maintainer again.

heppu commented 10 months ago

OK, I will do that, thanks!

namjaejeon commented 10 months ago

You need to give this problem is coming from nfsd also. with this link(https://www.spinics.net/lists/linux-rdma/msg117721.html). Thanks!.

heppu commented 9 months ago

I did some further verifications and found out that linux <-> linux RDMA connection works nicely with ConnectX-4 adapters but with windws client it doesn't. However I had couple ConnectX-3 cards available and decided to tests with those. Turns out that with ConnectX-3 cards linux <-> Win 10 RDMA connections works properly.

So my conclusion is that this must be Win 10 ConnectX-4 driver issue.