* [RFC PATCH 3/4] smb: server: defer the initial recv completion logic to smb_direct_negotiate_recv_work()
2025-12-02 21:15 [RFC PATCH 0/4] smb:smbdirect/server: introduce smb_direct_negotiate_recv_work Stefan Metzmacher
2025-12-02 21:15 ` [RFC PATCH 1/4] smb: smbdirect: introduce smbdirect_socket.connect.{lock,work} Stefan Metzmacher
2025-12-02 21:15 ` [RFC PATCH 2/4] smb: server: initialize recv_io->cqe.done = recv_done just once Stefan Metzmacher
@ 2025-12-02 21:15 ` Stefan Metzmacher
2025-12-02 21:15 ` [RFC PATCH 4/4] fs/smb/server/transport_rdma.c TMP DEBUG connect work Stefan Metzmacher
2025-12-04 6:15 ` [RFC PATCH 0/4] smb:smbdirect/server: introduce smb_direct_negotiate_recv_work Namjae Jeon
4 siblings, 0 replies; 6+ messages in thread
From: Stefan Metzmacher @ 2025-12-02 21:15 UTC (permalink / raw)
To: linux-cifs, samba-technical; +Cc: metze, Namjae Jeon, Steve French, Tom Talpey
The previous change to relax WARN_ON_ONCE(SMBDIRECT_SOCKET_*) checks in
recv_done() and smb_direct_cm_handler() seems to work around the
problem that the order of initial recv completion and
RDMA_CM_EVENT_ESTABLISHED is random, but it's still
a bit ugly.
This implements a better solution deferring the recv completion
processing to smb_direct_negotiate_recv_work(), which is queued
only if both events arrived.
In order to avoid more basic changes to the main recv_done
callback, I introduced a smb_direct_negotiate_recv_done,
which is only used for the first pdu, this will allow
further cleanup and simplifications in recv_done
as a future patch.
smb_direct_negotiate_recv_work() is also very basic
with only basic error checking and the transition
from SMBDIRECT_SOCKET_NEGOTIATE_NEEDED to
SMBDIRECT_SOCKET_NEGOTIATE_RUNNING, which allows
smb_direct_prepare() to continue as before.
Cc: Namjae Jeon <linkinjeon@kernel.org>
Cc: Steve French <smfrench@gmail.com>
Cc: Tom Talpey <tom@talpey.com>
Cc: linux-cifs@vger.kernel.org
Cc: samba-technical@lists.samba.org
Signed-off-by: Stefan Metzmacher <metze@samba.org>
---
fs/smb/server/transport_rdma.c | 170 +++++++++++++++++++++++++++------
1 file changed, 142 insertions(+), 28 deletions(-)
diff --git a/fs/smb/server/transport_rdma.c b/fs/smb/server/transport_rdma.c
index 222d1b5365e8..f585359684d4 100644
--- a/fs/smb/server/transport_rdma.c
+++ b/fs/smb/server/transport_rdma.c
@@ -242,6 +242,7 @@ static void smb_direct_disconnect_rdma_work(struct work_struct *work)
* disable[_delayed]_work_sync()
*/
disable_work(&sc->disconnect_work);
+ disable_work(&sc->connect.work);
disable_work(&sc->recv_io.posted.refill_work);
disable_delayed_work(&sc->idle.timer_work);
disable_work(&sc->idle.immediate_work);
@@ -297,6 +298,7 @@ smb_direct_disconnect_rdma_connection(struct smbdirect_socket *sc)
* not queued again but here we don't block and avoid
* disable[_delayed]_work_sync()
*/
+ disable_work(&sc->connect.work);
disable_work(&sc->recv_io.posted.refill_work);
disable_work(&sc->idle.immediate_work);
disable_delayed_work(&sc->idle.timer_work);
@@ -467,6 +469,7 @@ static void free_transport(struct smb_direct_transport *t)
*/
smb_direct_disconnect_wake_up_all(sc);
+ disable_work_sync(&sc->connect.work);
disable_work_sync(&sc->recv_io.posted.refill_work);
disable_delayed_work_sync(&sc->idle.timer_work);
disable_work_sync(&sc->idle.immediate_work);
@@ -635,28 +638,8 @@ static void recv_done(struct ib_cq *cq, struct ib_wc *wc)
switch (sc->recv_io.expected) {
case SMBDIRECT_EXPECT_NEGOTIATE_REQ:
- if (wc->byte_len < sizeof(struct smbdirect_negotiate_req)) {
- put_recvmsg(sc, recvmsg);
- smb_direct_disconnect_rdma_connection(sc);
- return;
- }
- sc->recv_io.reassembly.full_packet_received = true;
- /*
- * Some drivers (at least mlx5_ib) might post a
- * recv completion before RDMA_CM_EVENT_ESTABLISHED,
- * we need to adjust our expectation in that case.
- */
- if (!sc->first_error && sc->status == SMBDIRECT_SOCKET_RDMA_CONNECT_RUNNING)
- sc->status = SMBDIRECT_SOCKET_NEGOTIATE_NEEDED;
- if (SMBDIRECT_CHECK_STATUS_WARN(sc, SMBDIRECT_SOCKET_NEGOTIATE_NEEDED)) {
- put_recvmsg(sc, recvmsg);
- smb_direct_disconnect_rdma_connection(sc);
- return;
- }
- sc->status = SMBDIRECT_SOCKET_NEGOTIATE_RUNNING;
- enqueue_reassembly(sc, recvmsg, 0);
- wake_up(&sc->status_wait);
- return;
+ /* see smb_direct_negotiate_recv_done */
+ break;
case SMBDIRECT_EXPECT_DATA_TRANSFER: {
struct smbdirect_data_transfer *data_transfer =
(struct smbdirect_data_transfer *)recvmsg->packet;
@@ -742,6 +725,126 @@ static void recv_done(struct ib_cq *cq, struct ib_wc *wc)
smb_direct_disconnect_rdma_connection(sc);
}
+static void smb_direct_negotiate_recv_work(struct work_struct *work);
+
+static void smb_direct_negotiate_recv_done(struct ib_cq *cq, struct ib_wc *wc)
+{
+ struct smbdirect_recv_io *recv_io =
+ container_of(wc->wr_cqe, struct smbdirect_recv_io, cqe);
+ struct smbdirect_socket *sc = recv_io->socket;
+ unsigned long flags;
+
+ /*
+ * reset the common recv_done for later reuse.
+ */
+ recv_io->cqe.done = recv_done;
+
+ if (wc->status != IB_WC_SUCCESS || wc->opcode != IB_WC_RECV) {
+ put_recvmsg(sc, recv_io);
+ if (wc->status != IB_WC_WR_FLUSH_ERR) {
+ pr_err("Negotiate Recv error. status='%s (%d)' opcode=%d\n",
+ ib_wc_status_msg(wc->status), wc->status,
+ wc->opcode);
+ smb_direct_disconnect_rdma_connection(sc);
+ }
+ return;
+ }
+
+ ksmbd_debug(RDMA, "Negotiate Recv completed. status='%s (%d)', opcode=%d\n",
+ ib_wc_status_msg(wc->status), wc->status,
+ wc->opcode);
+
+ ib_dma_sync_single_for_cpu(sc->ib.dev,
+ recv_io->sge.addr,
+ recv_io->sge.length,
+ DMA_FROM_DEVICE);
+
+ /*
+ * This is an internal error!
+ */
+ if (WARN_ON_ONCE(sc->recv_io.expected != SMBDIRECT_EXPECT_NEGOTIATE_REQ)) {
+ put_recvmsg(sc, recv_io);
+ smb_direct_disconnect_rdma_connection(sc);
+ return;
+ }
+
+ /*
+ * Don't reset timer to the keepalive interval in
+ * this will be done in smb_direct_negotiate_recv_work.
+ */
+
+ /*
+ * Only remember the recv_io if it has enough bytes,
+ * this gives smb_direct_negotiate_recv_work enough
+ * information in order to disconnect if it was not
+ * valid.
+ */
+ sc->recv_io.reassembly.full_packet_received = true;
+ if (wc->byte_len >= sizeof(struct smbdirect_negotiate_req))
+ enqueue_reassembly(sc, recv_io, 0);
+ else
+ put_recvmsg(sc, recv_io);
+
+ /*
+ * Some drivers (at least mlx5_ib and irdma in roce mode)
+ * might post a recv completion before RDMA_CM_EVENT_ESTABLISHED,
+ * we need to adjust our expectation in that case.
+ *
+ * So we defer further processing of the negotiation
+ * to smb_direct_negotiate_recv_work().
+ *
+ * If we are already in SMBDIRECT_SOCKET_NEGOTIATE_NEEDED
+ * we queue the work directly otherwise
+ * smb_direct_cm_handler() will do it, when
+ * RDMA_CM_EVENT_ESTABLISHED arrived.
+ */
+ spin_lock_irqsave(&sc->connect.lock, flags);
+ if (!sc->first_error) {
+ INIT_WORK(&sc->connect.work, smb_direct_negotiate_recv_work);
+ if (sc->status == SMBDIRECT_SOCKET_NEGOTIATE_NEEDED)
+ queue_work(sc->workqueue, &sc->connect.work);
+ }
+ spin_unlock_irqrestore(&sc->connect.lock, flags);
+}
+
+static void smb_direct_negotiate_recv_work(struct work_struct *work)
+{
+ struct smbdirect_socket *sc =
+ container_of(work, struct smbdirect_socket, connect.work);
+ const struct smbdirect_socket_parameters *sp = &sc->parameters;
+ struct smbdirect_recv_io *recv_io;
+
+ if (sc->first_error)
+ return;
+
+ ksmbd_debug(RDMA, "Negotiate Recv Work running\n");
+
+ /*
+ * Reset timer to the keepalive interval in
+ * order to trigger our next keepalive message.
+ */
+ sc->idle.keepalive = SMBDIRECT_KEEPALIVE_NONE;
+ mod_delayed_work(sc->workqueue, &sc->idle.timer_work,
+ msecs_to_jiffies(sp->keepalive_interval_msec));
+
+ /*
+ * If smb_direct_negotiate_recv_done() detected an
+ * invalid request we want to disconnect.
+ */
+ recv_io = get_first_reassembly(sc);
+ if (!recv_io) {
+ smb_direct_disconnect_rdma_connection(sc);
+ return;
+ }
+
+ if (SMBDIRECT_CHECK_STATUS_WARN(sc, SMBDIRECT_SOCKET_NEGOTIATE_NEEDED)) {
+ smb_direct_disconnect_rdma_connection(sc);
+ return;
+ }
+ sc->status = SMBDIRECT_SOCKET_NEGOTIATE_RUNNING;
+ wake_up(&sc->status_wait);
+}
+
static int smb_direct_post_recv(struct smbdirect_socket *sc,
struct smbdirect_recv_io *recvmsg)
{
@@ -1731,6 +1834,7 @@ static int smb_direct_cm_handler(struct rdma_cm_id *cm_id,
struct rdma_cm_event *event)
{
struct smbdirect_socket *sc = cm_id->context;
+ unsigned long flags;
ksmbd_debug(RDMA, "RDMA CM event. cm_id=%p event=%s (%d)\n",
cm_id, rdma_event_msg(event->event), event->event);
@@ -1738,18 +1842,27 @@ static int smb_direct_cm_handler(struct rdma_cm_id *cm_id,
switch (event->event) {
case RDMA_CM_EVENT_ESTABLISHED: {
/*
- * Some drivers (at least mlx5_ib) might post a
- * recv completion before RDMA_CM_EVENT_ESTABLISHED,
+ * Some drivers (at least mlx5_ib and irdma in roce mode)
+ * might post a recv completion before RDMA_CM_EVENT_ESTABLISHED,
* we need to adjust our expectation in that case.
*
- * As we already started the negotiation, we just
- * ignore RDMA_CM_EVENT_ESTABLISHED here.
+ * If smb_direct_negotiate_recv_done was called first
+ * it initialized sc->connect.work only for us to
+ * start, so that we turned into
+ * SMBDIRECT_SOCKET_NEGOTIATE_NEEDED, before
+ * smb_direct_negotiate_recv_work() runs.
+ *
+ * If smb_direct_negotiate_recv_done didn't happen
+ * yet. sc->connect.work is still be disabled and
+ * queue_work() is a no-op.
*/
- if (!sc->first_error && sc->status > SMBDIRECT_SOCKET_RDMA_CONNECT_RUNNING)
- break;
if (SMBDIRECT_CHECK_STATUS_DISCONNECT(sc, SMBDIRECT_SOCKET_RDMA_CONNECT_RUNNING))
break;
sc->status = SMBDIRECT_SOCKET_NEGOTIATE_NEEDED;
+ spin_lock_irqsave(&sc->connect.lock, flags);
+ if (!sc->first_error)
+ queue_work(sc->workqueue, &sc->connect.work);
+ spin_unlock_irqrestore(&sc->connect.lock, flags);
wake_up(&sc->status_wait);
break;
}
@@ -1920,6 +2033,7 @@ static int smb_direct_prepare_negotiation(struct smbdirect_socket *sc)
recvmsg = get_free_recvmsg(sc);
if (!recvmsg)
return -ENOMEM;
+ recvmsg->cqe.done = smb_direct_negotiate_recv_done;
ret = smb_direct_post_recv(sc, recvmsg);
if (ret) {
--
2.43.0
^ permalink raw reply related [flat|nested] 6+ messages in thread* [RFC PATCH 4/4] fs/smb/server/transport_rdma.c TMP DEBUG connect work
2025-12-02 21:15 [RFC PATCH 0/4] smb:smbdirect/server: introduce smb_direct_negotiate_recv_work Stefan Metzmacher
` (2 preceding siblings ...)
2025-12-02 21:15 ` [RFC PATCH 3/4] smb: server: defer the initial recv completion logic to smb_direct_negotiate_recv_work() Stefan Metzmacher
@ 2025-12-02 21:15 ` Stefan Metzmacher
2025-12-04 6:15 ` [RFC PATCH 0/4] smb:smbdirect/server: introduce smb_direct_negotiate_recv_work Namjae Jeon
4 siblings, 0 replies; 6+ messages in thread
From: Stefan Metzmacher @ 2025-12-02 21:15 UTC (permalink / raw)
To: linux-cifs, samba-technical; +Cc: metze
irdma in roce mode with Windows 2025 as client:
root@rdmatest04l0:~# dmesg -e| grep 0000000010731e17
[ +0.002358] [ T6642] ksmbd: smb_direct: smb_direct_prepare_negotiation:2121: 0000000010731e17 0 0 7 RDMA_CONNECT_NEEDED
[ +0.002087] [ T6642] ksmbd: smb_direct: smb_direct_prepare_negotiation:2134: 0000000010731e17 0 0 8 RDMA_CONNECT_RUNNING
[ +0.000112] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2479: 0000000010731e17 0 0 8 RDMA_CONNECT_RUNNING
[ +0.000019] [ T330] ksmbd: smb_direct: smb_direct_negotiate_recv_done: 0000000010731e17 RDMA_CONNECT_RUNNING
[ +0.000018] [ T6642] ksmbd: smb_direct: smb_direct_cm_handler: 0000000010731e17 RDMA_CONNECT_RUNNING
[ +0.000004] [ T6642] ksmbd: smb_direct: smb_direct_cm_handler: 0000000010731e17 NEGOTIATE_NEEDED queue_work(smb_direct_negotiate_recv_work)
[ +0.000010] [ T561] ksmbd: smb_direct: smb_direct_negotiate_recv_work:842: 0000000010731e17 0 0 10 NEGOTIATE_NEEDED
[ +0.000002] [ T561] ksmbd: smb_direct: smb_direct_negotiate_recv_work:854: 0000000010731e17 0 0 10 NEGOTIATE_NEEDED
[ +0.000001] [ T561] ksmbd: smb_direct: smb_direct_negotiate_recv_work:880: 0000000010731e17 0 0 10 NEGOTIATE_NEEDED
[ +0.000003] [ T561] ksmbd: smb_direct: smb_direct_negotiate_recv_work:892: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000002] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2491: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000012] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2505: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000006] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2516: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000003] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2536: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000008] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2556: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000036] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2579: 0000000010731e17 0 0 11 NEGOTIATE_RUNNING
[ +0.000106] [ T8824] ksmbd: smb_direct: smb_direct_prepare:2589: 0000000010731e17 0 0 13 CONNECTED
root@rdmatest04l0:~# dmesg -e| grep 00000000d50d5bf5
[ +0.002987] [ T4211] ksmbd: smb_direct: smb_direct_prepare_negotiation:2120: 00000000d50d5bf5 0 0 7 RDMA_CONNECT_NEEDED
[ +0.002146] [ T4211] ksmbd: smb_direct: smb_direct_prepare_negotiation:2133: 00000000d50d5bf5 0 0 8 RDMA_CONNECT_RUNNING
[ +0.000101] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2478: 00000000d50d5bf5 0 0 8 RDMA_CONNECT_RUNNING
[ +0.000012] [ T4339] ksmbd: smb_direct: smb_direct_cm_handler: 00000000d50d5bf5 RDMA_CONNECT_RUNNING
[ +0.000011] [ T4339] ksmbd: smb_direct: smb_direct_cm_handler: 00000000d50d5bf5 NEGOTIATE_NEEDED queue_work(no-op)
[ +0.000073] [ T239] ksmbd: smb_direct: smb_direct_negotiate_recv_done: 00000000d50d5bf5 NEGOTIATE_NEEDED
[ +0.000023] [ T239] ksmbd: smb_direct: smb_direct_negotiate_recv_work:841: 00000000d50d5bf5 0 0 10 NEGOTIATE_NEEDED
[ +0.000009] [ T239] ksmbd: smb_direct: smb_direct_negotiate_recv_work:853: 00000000d50d5bf5 0 0 10 NEGOTIATE_NEEDED
[ +0.000009] [ T239] ksmbd: smb_direct: smb_direct_negotiate_recv_work:879: 00000000d50d5bf5 0 0 10 NEGOTIATE_NEEDED
[ +0.000004] [ T239] ksmbd: smb_direct: smb_direct_negotiate_recv_work:891: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.001212] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2490: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000004] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2504: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000002] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2515: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000003] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2535: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000005] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2555: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000210] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2578: 00000000d50d5bf5 0 0 11 NEGOTIATE_RUNNING
[ +0.000080] [ T6659] ksmbd: smb_direct: smb_direct_prepare:2588: 00000000d50d5bf5 0 0 13 CONNECTED
---
fs/smb/server/transport_rdma.c | 146 +++++++++++++++++++++++++++++++++
1 file changed, 146 insertions(+)
diff --git a/fs/smb/server/transport_rdma.c b/fs/smb/server/transport_rdma.c
index f585359684d4..36be95ebcfcc 100644
--- a/fs/smb/server/transport_rdma.c
+++ b/fs/smb/server/transport_rdma.c
@@ -454,12 +454,28 @@ static void free_transport(struct smb_direct_transport *t)
struct smbdirect_socket *sc = &t->socket;
struct smbdirect_recv_io *recvmsg;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
+
disable_work_sync(&sc->disconnect_work);
if (sc->status < SMBDIRECT_SOCKET_DISCONNECTING)
smb_direct_disconnect_rdma_work(&sc->disconnect_work);
if (sc->status < SMBDIRECT_SOCKET_DISCONNECTED)
wait_event(sc->status_wait, sc->status == SMBDIRECT_SOCKET_DISCONNECTED);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
+
/*
* Wake up all waiters in all wait queues
* in order to notice the broken connection.
@@ -474,6 +490,14 @@ static void free_transport(struct smb_direct_transport *t)
disable_delayed_work_sync(&sc->idle.timer_work);
disable_work_sync(&sc->idle.immediate_work);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
+
if (sc->rdma.cm_id)
rdma_lock_handler(sc->rdma.cm_id);
@@ -801,6 +825,7 @@ static void smb_direct_negotiate_recv_done(struct ib_cq *cq, struct ib_wc *wc)
spin_lock_irqsave(&sc->connect.lock, flags);
if (!sc->first_error) {
INIT_WORK(&sc->connect.work, smb_direct_negotiate_recv_work);
+ pr_notice("%s: %p %s\n", __func__, sc, smbdirect_socket_status_string(sc->status));
if (sc->status == SMBDIRECT_SOCKET_NEGOTIATE_NEEDED)
queue_work(sc->workqueue, &sc->connect.work);
}
@@ -814,10 +839,25 @@ static void smb_direct_negotiate_recv_work(struct work_struct *work)
const struct smbdirect_socket_parameters *sp = &sc->parameters;
struct smbdirect_recv_io *recv_io;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
+
if (sc->first_error)
return;
ksmbd_debug(RDMA, "Negotiate Recv Work running\n");
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
/*
* Reset timer to the keepalive interval in
@@ -837,11 +877,25 @@ static void smb_direct_negotiate_recv_work(struct work_struct *work)
return;
}
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
if (SMBDIRECT_CHECK_STATUS_WARN(sc, SMBDIRECT_SOCKET_NEGOTIATE_NEEDED)) {
smb_direct_disconnect_rdma_connection(sc);
return;
}
sc->status = SMBDIRECT_SOCKET_NEGOTIATE_RUNNING;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
wake_up(&sc->status_wait);
}
@@ -1816,6 +1870,14 @@ static void smb_direct_disconnect(struct ksmbd_transport *t)
struct smbdirect_socket *sc = &st->socket;
ksmbd_debug(RDMA, "Disconnecting cm_id=%p\n", sc->rdma.cm_id);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
+
free_transport(st);
}
@@ -1826,6 +1888,13 @@ static void smb_direct_shutdown(struct ksmbd_transport *t)
struct smbdirect_socket *sc = &st->socket;
ksmbd_debug(RDMA, "smb-direct shutdown cm_id=%p\n", sc->rdma.cm_id);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
smb_direct_disconnect_rdma_work(&sc->disconnect_work);
}
@@ -1856,10 +1925,15 @@ static int smb_direct_cm_handler(struct rdma_cm_id *cm_id,
* yet. sc->connect.work is still be disabled and
* queue_work() is a no-op.
*/
+ pr_notice("%s: %p %s\n", __func__, sc, smbdirect_socket_status_string(sc->status));
if (SMBDIRECT_CHECK_STATUS_DISCONNECT(sc, SMBDIRECT_SOCKET_RDMA_CONNECT_RUNNING))
break;
sc->status = SMBDIRECT_SOCKET_NEGOTIATE_NEEDED;
spin_lock_irqsave(&sc->connect.lock, flags);
+ pr_notice("%s: %p %s %s\n", __func__, sc, smbdirect_socket_status_string(sc->status),
+ sc->connect.work.func == smb_direct_negotiate_recv_work ?
+ "queue_work(smb_direct_negotiate_recv_work)":
+ "queue_work(no-op)");
if (!sc->first_error)
queue_work(sc->workqueue, &sc->connect.work);
spin_unlock_irqrestore(&sc->connect.lock, flags);
@@ -1869,7 +1943,9 @@ static int smb_direct_cm_handler(struct rdma_cm_id *cm_id,
case RDMA_CM_EVENT_DEVICE_REMOVAL:
case RDMA_CM_EVENT_DISCONNECTED: {
sc->status = SMBDIRECT_SOCKET_DISCONNECTED;
+ pr_notice("%s: %p %s\n", __func__, sc, smbdirect_socket_status_string(sc->status));
smb_direct_disconnect_rdma_work(&sc->disconnect_work);
+ pr_notice("%s: %p %s\n", __func__, sc, smbdirect_socket_status_string(sc->status));
if (sc->ib.qp)
ib_drain_qp(sc->ib.qp);
break;
@@ -2042,12 +2118,26 @@ static int smb_direct_prepare_negotiation(struct smbdirect_socket *sc)
}
recv_posted = true;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
ret = smb_direct_accept_client(sc);
if (ret) {
pr_err("Can't accept client\n");
goto out_err;
}
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
return 0;
out_err:
/*
@@ -2386,11 +2476,25 @@ static int smb_direct_prepare(struct ksmbd_transport *t)
* Everything else is unexpected and an error.
*/
ksmbd_debug(RDMA, "Waiting for SMB_DIRECT negotiate request\n");
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
ret = wait_event_interruptible_timeout(sc->status_wait,
sc->status != SMBDIRECT_SOCKET_RDMA_CONNECT_NEEDED &&
sc->status != SMBDIRECT_SOCKET_RDMA_CONNECT_RUNNING &&
sc->status != SMBDIRECT_SOCKET_NEGOTIATE_NEEDED,
msecs_to_jiffies(sp->negotiate_timeout_msec));
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
if (ret <= 0 || sc->status != SMBDIRECT_SOCKET_NEGOTIATE_RUNNING)
return ret < 0 ? ret : -ETIMEDOUT;
@@ -2398,10 +2502,24 @@ static int smb_direct_prepare(struct ksmbd_transport *t)
if (!recvmsg)
return -ECONNABORTED;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
ret = smb_direct_check_recvmsg(recvmsg);
if (ret)
goto put;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
req = (struct smbdirect_negotiate_req *)recvmsg->packet;
sp->max_recv_size = min_t(int, sp->max_recv_size,
le32_to_cpu(req->preferred_send_size));
@@ -2415,6 +2533,13 @@ static int smb_direct_prepare(struct ksmbd_transport *t)
sc->recv_io.credits.target = min_t(u16, sc->recv_io.credits.target, sp->recv_credit_max);
sc->recv_io.credits.target = max_t(u16, sc->recv_io.credits.target, 1);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
put:
spin_lock_irqsave(&sc->recv_io.reassembly.lock, flags);
sc->recv_io.reassembly.queue_length--;
@@ -2428,6 +2553,13 @@ static int smb_direct_prepare(struct ksmbd_transport *t)
if (ret)
goto respond;
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
/*
* We negotiated with success, so we need to refill the recv queue.
* We do that with sc->idle.immediate_work still being disabled
@@ -2444,9 +2576,23 @@ static int smb_direct_prepare(struct ksmbd_transport *t)
return sc->first_error;
INIT_WORK(&sc->idle.immediate_work, smb_direct_send_immediate_work);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
respond:
ret = smb_direct_send_negotiate_response(sc, ret);
+ pr_notice("%s:%u: %p %d %1pe %d %s\n",
+ __func__, __LINE__,
+ sc,
+ sc->first_error,
+ SMBDIRECT_DEBUG_ERR_PTR(sc->first_error),
+ sc->status,
+ smbdirect_socket_status_string(sc->status));
return ret;
}
--
2.43.0
^ permalink raw reply related [flat|nested] 6+ messages in thread