Signed-off-by: David Howells <dhowells@xxxxxxxxxx>
cc: Steve French <sfrench@xxxxxxxxx>
cc: Paulo Alcantara <pc@xxxxxxxxxxxxx>
cc: Shyam Prasad N <sprasad@xxxxxxxxxxxxx>
cc: Tom Talpey <tom@xxxxxxxxxx>
cc: linux-cifs@xxxxxxxxxxxxxxx
cc: netfs@xxxxxxxxxxxxxxx
cc: linux-fsdevel@xxxxxxxxxxxxxxx
---
fs/smb/client/cifsglob.h | 1 +
fs/smb/client/cifsproto.h | 5 +--
fs/smb/client/connect.c | 14 +++++---
fs/smb/client/smb2ops.c | 3 +-
fs/smb/client/smb2pdu.c | 6 ++--
fs/smb/client/smb2transport.c | 2 +-
fs/smb/client/trace.h | 61 +++++++++++++++++++++++++++++++++++
fs/smb/client/transport.c | 57 ++++++++++++++++++++++++++------
8 files changed, 127 insertions(+), 22 deletions(-)
diff --git a/fs/smb/client/cifsglob.h b/fs/smb/client/cifsglob.h
index 14b132fb14e0..045a29cedf0e 100644
--- a/fs/smb/client/cifsglob.h
+++ b/fs/smb/client/cifsglob.h
@@ -1734,6 +1734,7 @@ struct smb_message {
void *request; /* Pointer to request message body */
wait_queue_head_t waitq; /* Wait queue for message events */
refcount_t ref;
+ unsigned int debug_id; /* Debugging ID for tracing */
bool sensitive; /* Request contains sensitive data */
bool cancelled; /* T if cancelled */
unsigned int sr_flags; /* Flags passed to send_recv() */
diff --git a/fs/smb/client/cifsproto.h b/fs/smb/client/cifsproto.h
index abae67d83499..074b65bb57a5 100644
--- a/fs/smb/client/cifsproto.h
+++ b/fs/smb/client/cifsproto.h
@@ -761,8 +761,9 @@ static inline void cifs_free_open_info(struct cifs_open_info_data *data)
}
struct smb_message *smb_message_alloc(enum smb2_command cmd, gfp_t gfp);
-void smb_get_message(struct smb_message *smb);
-void smb_put_message(struct smb_message *smb);
+void smb_see_message(struct smb_message *smb, enum smb_message_trace trace);
+void smb_get_message(struct smb_message *smb, enum smb_message_trace trace);
+void smb_put_message(struct smb_message *smb, enum smb_message_trace trace);
void smb_put_messages(struct smb_message *smb);
#endif /* _CIFSPROTO_H */
diff --git a/fs/smb/client/connect.c b/fs/smb/client/connect.c
index 9bd19dd91d35..74b88304a782 100644
--- a/fs/smb/client/connect.c
+++ b/fs/smb/client/connect.c
@@ -323,6 +323,7 @@ cifs_abort_connection(struct TCP_Server_Info *server)
cifs_dbg(FYI, "%s: moving mids to private list\n", __func__);
spin_lock(&server->mid_lock);
list_for_each_entry_safe(smb, nsmb, &server->pending_mid_q, qhead) {
+ smb_see_message(smb, smb_message_trace_see_abort_conn);
if (smb->mid_state == MID_REQUEST_SUBMITTED)
smb->mid_state = MID_RETRY_NEEDED;
list_move(&smb->qhead, &retry_list);
@@ -335,7 +336,7 @@ cifs_abort_connection(struct TCP_Server_Info *server)
list_for_each_entry_safe(smb, nsmb, &retry_list, qhead) {
list_del_init(&smb->qhead);
smb->callback(server, smb);
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_abort_conn);
}
if (cifs_rdma_enabled(server)) {
@@ -885,6 +886,7 @@ is_smb_response(struct TCP_Server_Info *server, unsigned char type)
*/
spin_lock(&server->mid_lock);
list_for_each_entry_safe(smb, nsmb, &server->pending_mid_q, qhead) {
+ smb_see_message(smb, smb_message_trace_see_is_smb_resp);
list_move(&smb->qhead, &dispose_list);
smb->mid_flags |= MID_DELETED;
}
@@ -918,7 +920,7 @@ is_smb_response(struct TCP_Server_Info *server, unsigned char type)
smb->mid_rc = mid_rc;
smb->mid_state = MID_RC;
smb->callback(server, smb);
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_is_smb_resp);
}
/*
@@ -968,6 +970,7 @@ dequeue_mid(struct smb_message *smb, bool malformed)
spin_unlock(&smb->server->mid_lock);
pr_warn_once("trying to dequeue a deleted mid\n");
} else {
+ smb_see_message(smb, smb_message_trace_see_dequeue_mid);
list_del_init(&smb->qhead);
smb->mid_flags |= MID_DELETED;
spin_unlock(&smb->server->mid_lock);
@@ -1101,6 +1104,7 @@ clean_demultiplex_info(struct TCP_Server_Info *server)
spin_lock(&server->mid_lock);
list_for_each_entry_safe(smb, smb2, &server->pending_mid_q, qhead) {
cifs_dbg(FYI, "Clearing mid %llu\n", smb->mid);
+ smb_see_message(smb, smb_message_trace_see_clean_demux);
smb->mid_state = MID_SHUTDOWN;
list_move(&smb->qhead, &dispose_list);
smb->mid_flags |= MID_DELETED;
@@ -1112,7 +1116,7 @@ clean_demultiplex_info(struct TCP_Server_Info *server)
cifs_dbg(FYI, "Callback mid %llu\n", smb->mid);
list_del_init(&smb->qhead);
smb->callback(server, smb);
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_clean_demux);
}
/* 1/8th of sec is more than enough time for them to exit */
msleep(125);
@@ -1355,7 +1359,7 @@ cifs_demultiplex_thread(void *p)
if (length < 0) {
for (i = 0; i < num_smbs; i++)
if (smbs[i])
- smb_put_message(smbs[i]);
+ smb_put_message(smbs[i], smb_message_trace_put_demux);
continue;
}
@@ -1390,7 +1394,7 @@ cifs_demultiplex_thread(void *p)
if (!smbs[i]->multiRsp || smbs[i]->multiEnd)
smbs[i]->callback(server, smbs[i]);
- smb_put_message(smbs[i]);
+ smb_put_message(smbs[i], smb_message_trace_put_demux_cb);
} else if (server->ops->is_oplock_break &&
server->ops->is_oplock_break(bufs[i],
server)) {
diff --git a/fs/smb/client/smb2ops.c b/fs/smb/client/smb2ops.c
index 63226bbba3d1..1e24489b55e3 100644
--- a/fs/smb/client/smb2ops.c
+++ b/fs/smb/client/smb2ops.c
@@ -408,6 +408,7 @@ __smb2_find_mid(struct TCP_Server_Info *server, char *buf, bool dequeue)
if ((smb->mid == wire_mid) &&
(smb->mid_state == MID_REQUEST_SUBMITTED) &&
(smb->command_id == command)) {
+ smb_see_message(smb, smb_message_trace_see_find_mid);
if (dequeue) {
list_del_init(&smb->qhead);
smb->mid_flags |= MID_DELETED;
@@ -4726,7 +4727,7 @@ static void smb2_decrypt_offload(struct work_struct *work)
spin_unlock(&dw->server->srv_lock);
}
}
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_decrypt_offload);
}
free_pages:
diff --git a/fs/smb/client/smb2pdu.c b/fs/smb/client/smb2pdu.c
index 8d50036fd028..3009acf0d884 100644
--- a/fs/smb/client/smb2pdu.c
+++ b/fs/smb/client/smb2pdu.c
@@ -4305,7 +4305,7 @@ SMB2_echo(struct TCP_Server_Info *server)
cifs_dbg(FYI, "Echo request failed: %d\n", rc);
cifs_small_buf_release(req);
- smb_put_message(smb);
+ smb_put_messages(smb);
return rc;
}
@@ -4753,7 +4753,7 @@ smb2_async_readv(struct cifs_io_subrequest *rdata)
async_readv_out:
cifs_small_buf_release(buf);
- smb_put_message(smb);
+ smb_put_messages(smb);
return rc;
}
@@ -5127,7 +5127,7 @@ smb2_async_writev(struct cifs_io_subrequest *wdata)
async_writev_out:
cifs_small_buf_release(req);
- smb_put_message(smb);
+ smb_put_messages(smb);
out:
if (rc) {
trace_smb3_rw_credits(wdata->rreq->debug_id,
diff --git a/fs/smb/client/smb2transport.c b/fs/smb/client/smb2transport.c
index 7194082bb5ac..da6377521fe9 100644
--- a/fs/smb/client/smb2transport.c
+++ b/fs/smb/client/smb2transport.c
@@ -801,7 +801,7 @@ smb2_get_mid_entry(struct cifs_ses *ses, struct TCP_Server_Info *server,
smb2_init_mid(smb, server);
- smb_get_message(smb);
+ smb_get_message(smb, smb_message_trace_get_enqueue_sync);
spin_lock(&server->mid_lock);
list_add_tail(&smb->qhead, &server->pending_mid_q);
spin_unlock(&server->mid_lock);
diff --git a/fs/smb/client/trace.h b/fs/smb/client/trace.h
index 93e5b2bb9f28..5cee63960419 100644
--- a/fs/smb/client/trace.h
+++ b/fs/smb/client/trace.h
@@ -20,6 +20,45 @@
/*
* Specify enums for tracing information.
*/
+#define smb_message_traces \
+ EM(smb_message_trace_alloc_cancel, "AL Cancel ") \
+ EM(smb_message_trace_alloc_change_notify, "AL Change-Nfy") \
+ EM(smb_message_trace_alloc_close, "AL Close ") \
+ EM(smb_message_trace_alloc_create, "AL Create ") \
+ EM(smb_message_trace_alloc_echo, "AL Echo ") \
+ EM(smb_message_trace_alloc_flush, "AL Flush ") \
+ EM(smb_message_trace_alloc_ioctl, "AL Ioctl ") \
+ EM(smb_message_trace_alloc_lock, "AL Lock ") \
+ EM(smb_message_trace_alloc_logoff, "AL Logoff ") \
+ EM(smb_message_trace_alloc_negotiate, "AL Negotiate ") \
+ EM(smb_message_trace_alloc_oplock_break, "AL Oplock-Brk") \
+ EM(smb_message_trace_alloc_query_directory, "AL Query-Dir ") \
+ EM(smb_message_trace_alloc_query_info, "AL Query-Info") \
+ EM(smb_message_trace_alloc_read, "AL Read ") \
+ EM(smb_message_trace_alloc_session_setup, "AL Sess-setup") \
+ EM(smb_message_trace_alloc_set_info, "AL Set-Info ") \
+ EM(smb_message_trace_alloc_srv_to_cln_notif, "AL s2c-Notify") \
+ EM(smb_message_trace_alloc_tree_connect, "AL Tree-conn ") \
+ EM(smb_message_trace_alloc_tree_disconnect, "AL Tree-disc ") \
+ EM(smb_message_trace_alloc_write, "AL Write ") \
+ EM(smb_message_trace_free, "FREE ") \
+ EM(smb_message_trace_get_call_async, "GET call-asyn") \
+ EM(smb_message_trace_get_enqueue_sync, "GET enq-sync ") \
+ EM(smb_message_trace_put_abort_conn, "PUT abrt-conn") \
+ EM(smb_message_trace_put_clean_demux, "PUT cln-demux") \
+ EM(smb_message_trace_put_decrypt_offload, "PUT decrypt-o") \
+ EM(smb_message_trace_put_demux, "PUT demux ") \
+ EM(smb_message_trace_put_demux_cb, "PUT demux-cb ") \
+ EM(smb_message_trace_put_discard_message, "PUT disc-msg ") \
+ EM(smb_message_trace_put_is_smb_resp, "PUT is-s-resp") \
+ EM(smb_message_trace_put_messages, "PUT messages ") \
+ EM(smb_message_trace_see_abort_conn, "SEE abrt-conn") \
+ EM(smb_message_trace_see_clean_demux, "SEE cln-demux") \
+ EM(smb_message_trace_see_dequeue_mid, "SEE deque-mid") \
+ EM(smb_message_trace_see_find_mid, "SEE find-mid ") \
+ EM(smb_message_trace_see_is_smb_resp, "SEE is-s-resp") \
+ E_(smb_message_trace_see_wake_up_task, "SEE wake-task")
+
#define smb3_rw_credits_traces \
EM(cifs_trace_rw_credits_call_readv_adjust, "rd-call-adj") \
EM(cifs_trace_rw_credits_call_writev_adjust, "wr-call-adj") \
@@ -79,6 +118,7 @@
#define EM(a, b) a,
#define E_(a, b) a
+enum smb_message_trace { smb_message_traces } __mode(byte);
enum smb3_rw_credits_trace { smb3_rw_credits_traces } __mode(byte);
enum smb3_tcon_ref_trace { smb3_tcon_ref_traces } __mode(byte);
@@ -92,6 +132,7 @@ enum smb3_tcon_ref_trace { smb3_tcon_ref_traces } __mode(byte);
#define EM(a, b) TRACE_DEFINE_ENUM(a);
#define E_(a, b) TRACE_DEFINE_ENUM(a);
+smb_message_traces;
smb3_rw_credits_traces;
smb3_tcon_ref_traces;
@@ -1573,6 +1614,26 @@ TRACE_EVENT(smb3_rw_credits,
__entry->server_credits, __entry->in_flight)
);
+TRACE_EVENT(smb3_message,
+ TP_PROTO(unsigned int smb_message_debug_id, int ref,
+ enum smb_message_trace trace),
+ TP_ARGS(smb_message_debug_id, ref, trace),
+ TP_STRUCT__entry(
+ __field(unsigned int, smb_message)
+ __field(int, ref)
+ __field(enum smb_message_trace, trace)
+ ),
+ TP_fast_assign(
+ __entry->smb_message = smb_message_debug_id;
+ __entry->ref = ref;
+ __entry->trace = trace;
+ ),
+ TP_printk("SMB=%08x %s r=%d",
+ __entry->smb_message,
+ __print_symbolic(__entry->trace, smb_message_traces),
+ __entry->ref)
+ );
+
#undef EM
#undef E_
diff --git a/fs/smb/client/transport.c b/fs/smb/client/transport.c
index 7a4788b54a07..2ccfdd6b958b 100644
--- a/fs/smb/client/transport.c
+++ b/fs/smb/client/transport.c
@@ -34,12 +34,14 @@
struct smb_message *smb_message_alloc(enum smb2_command cmd, gfp_t gfp)
{
+ static atomic_t debug_ids;
struct smb_message *smb;
smb = mempool_alloc(&smb_message_pool, gfp);
if (smb) {
memset(smb, 0, sizeof(*smb));
refcount_set(&smb->ref, 1);
+ smb->debug_id = atomic_inc_return(&debug_ids);
smb->command_id = cmd;
smb->when_alloc = jiffies;
smb->pid = current->pid;
@@ -52,22 +54,47 @@ struct smb_message *smb_message_alloc(enum smb2_command cmd, gfp_t gfp)
smb->mid_state = MID_REQUEST_ALLOCATED;
init_waitqueue_head(&smb->waitq);
+ trace_smb3_message(smb->debug_id, 1, (enum smb_message_trace)cmd);
}
return smb;
}
-void smb_get_message(struct smb_message *smb)
+void smb_see_message(struct smb_message *smb, enum smb_message_trace trace)
{
- refcount_inc(&smb->ref);
+ trace_smb3_message(smb->debug_id, refcount_read(&smb->ref), trace);
+}
+
+void smb_get_message(struct smb_message *smb, enum smb_message_trace trace)
+{
+ int r;
+
+ __refcount_inc(&smb->ref, &r);
+ trace_smb3_message(smb->debug_id, r + 1, trace);
+ printk("GET SMB=%08x{%d} %pSR\n",
+ smb->debug_id, r + 1, __builtin_return_address(0));
+}
+
+static void smb_free_message(struct smb_message *smb)
+{
+ trace_smb3_message(smb->debug_id, refcount_read(&smb->ref),
+ smb_message_trace_free);
+ mempool_free(smb, &smb_message_pool);
}
/*
* Drop a ref on a message. This does not touch the chained messages.
*/
-void smb_put_message(struct smb_message *smb)
+void smb_put_message(struct smb_message *smb, enum smb_message_trace trace)
{
- if (refcount_dec_and_test(&smb->ref))
- mempool_free(smb, &smb_message_pool);
+ unsigned int debug_id = smb->debug_id;
+ bool dead;
+ int r;
+
+ dead = __refcount_dec_and_test(&smb->ref, &r);
+ trace_smb3_message(debug_id, r - 1, trace);
+ printk("PUT SMB=%08x{%d} %pSR\n", debug_id, r - 1, __builtin_return_address(0));
+ if (dead)
+ smb_free_message(smb);
}
/*
@@ -79,8 +106,17 @@ void smb_put_messages(struct smb_message *smb)
struct smb_message *next;
for (; smb; smb = next) {
+ unsigned int debug_id = smb->debug_id;
+ bool dead;
+ int r;
+
next = smb->next;
- smb_put_message(smb);
+ dead = __refcount_dec_and_test(&smb->ref, &r);
+ trace_smb3_message(debug_id, r - 1, smb_message_trace_put_messages);
+ printk("PUTS SMB=%08x{%d} %pSR\n",
+ debug_id, r - 1, __builtin_return_address(0));
+ if (dead)
+ smb_free_message(smb);
}
}
@@ -89,6 +125,7 @@ cifs_wake_up_task(struct TCP_Server_Info *server, struct smb_message *smb)
{
if (smb->mid_state == MID_RESPONSE_RECEIVED)
smb->mid_state = MID_RESPONSE_READY;
+ smb_see_message(smb, smb_message_trace_see_wake_up_task);
wake_up_all(&smb->waitq);
}
@@ -189,7 +226,7 @@ static void smb_discard_messages(struct TCP_Server_Info *server, struct smb_mess
for (smb = head_smb; smb; smb = next) {
next = smb->next;
if (discard_message(server, smb))
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_discard_message);
}
}
@@ -877,7 +914,7 @@ cifs_call_async(struct TCP_Server_Info *server, struct smb_message *smb,
smb->mid_state = MID_REQUEST_SUBMITTED;
/* put it on the pending_mid_q */
- smb_get_message(smb);
+ smb_get_message(smb, smb_message_trace_get_call_async);
spin_lock(&server->mid_lock);
list_add_tail(&smb->qhead, &server->pending_mid_q);
spin_unlock(&server->mid_lock);
@@ -893,7 +930,7 @@ cifs_call_async(struct TCP_Server_Info *server, struct smb_message *smb,
revert_current_mid(server, smb->credits_consumed);
server->sequence_number -= 2;
if (discard_message(server, smb))
- smb_put_message(smb);
+ smb_put_message(smb, smb_message_trace_put_discard_message);
}
cifs_server_unlock(server);
@@ -1295,7 +1332,7 @@ compound_send_recv(const unsigned int xid, struct cifs_ses *ses,
rc = smb_send_recv_messages(xid, ses, server, head_smb, flags);
error:
- smb_put_messages(smb);
+ smb_put_messages(head_smb);
return rc;
}
