@@ -290,7 +290,7 @@ struct smb_version_operations {
int (*check_receive)(struct mid_q_entry *, struct TCP_Server_Info *,
bool);
void (*add_credits)(struct TCP_Server_Info *server,
- const struct cifs_credits *credits,
+ struct cifs_credits *credits,
const int optype);
void (*set_credits)(struct TCP_Server_Info *, const int);
int * (*get_credits_field)(struct TCP_Server_Info *, const int);
@@ -550,8 +550,8 @@ struct smb_version_operations {
size_t *, struct cifs_credits *);
/* adjust previously taken mtu credits to request size */
int (*adjust_credits)(struct TCP_Server_Info *server,
- struct cifs_credits *credits,
- const unsigned int payload_size);
+ struct cifs_io_subrequest *subreq,
+ unsigned int /*enum smb3_rw_credits_trace*/ trace);
/* check if we need to issue closedir */
bool (*dir_needs_close)(struct cifsFileInfo *);
long (*fallocate)(struct file *, struct cifs_tcon *, int, loff_t,
@@ -848,6 +848,9 @@ static inline void cifs_server_unlock(struct TCP_Server_Info *server)
struct cifs_credits {
unsigned int value;
unsigned int instance;
+ unsigned int in_flight_check;
+ unsigned int rreq_debug_id;
+ unsigned int rreq_debug_index;
};
static inline unsigned int
@@ -873,7 +876,7 @@ has_credits(struct TCP_Server_Info *server, int *credits, int num_credits)
}
static inline void
-add_credits(struct TCP_Server_Info *server, const struct cifs_credits *credits,
+add_credits(struct TCP_Server_Info *server, struct cifs_credits *credits,
const int optype)
{
server->ops->add_credits(server, credits, optype);
@@ -897,11 +900,11 @@ set_credits(struct TCP_Server_Info *server, const int val)
}
static inline int
-adjust_credits(struct TCP_Server_Info *server, struct cifs_credits *credits,
- const unsigned int payload_size)
+adjust_credits(struct TCP_Server_Info *server, struct cifs_io_subrequest *subreq,
+ unsigned int /* enum smb3_rw_credits_trace */ trace)
{
return server->ops->adjust_credits ?
- server->ops->adjust_credits(server, credits, payload_size) : 0;
+ server->ops->adjust_credits(server, subreq, trace) : 0;
}
static inline __le64
@@ -80,6 +80,16 @@ static void cifs_prepare_write(struct netfs_io_subrequest *subreq)
return netfs_prepare_write_failed(subreq);
}
+ wdata->credits.rreq_debug_id = subreq->rreq->debug_id;
+ wdata->credits.rreq_debug_index = subreq->debug_index;
+ wdata->credits.in_flight_check = 1;
+ trace_smb3_rw_credits(wdata->rreq->debug_id,
+ wdata->subreq.debug_index,
+ wdata->credits.value,
+ server->credits, server->in_flight,
+ wdata->credits.value,
+ cifs_trace_rw_credits_write_prepare);
+
#ifdef CONFIG_CIFS_SMB_DIRECT
if (server->smbd_conn)
subreq->max_nr_segs = server->smbd_conn->max_frmr_depth;
@@ -101,7 +111,7 @@ static void cifs_issue_write(struct netfs_io_subrequest *subreq)
goto fail;
}
- rc = adjust_credits(wdata->server, &wdata->credits, wdata->subreq.len);
+ rc = adjust_credits(wdata->server, wdata, cifs_trace_rw_credits_issue_write_adjust);
if (rc)
goto fail;
@@ -160,6 +170,16 @@ static bool cifs_clamp_length(struct netfs_io_subrequest *subreq)
return false;
}
+ rdata->credits.in_flight_check = 1;
+ rdata->credits.rreq_debug_id = rreq->debug_id;
+ rdata->credits.rreq_debug_index = subreq->debug_index;
+
+ trace_smb3_rw_credits(rdata->rreq->debug_id,
+ rdata->subreq.debug_index,
+ rdata->credits.value,
+ server->credits, server->in_flight, 0,
+ cifs_trace_rw_credits_read_clamp);
+
subreq->len = min_t(size_t, subreq->len, rsize);
#ifdef CONFIG_CIFS_SMB_DIRECT
if (server->smbd_conn)
@@ -203,7 +223,7 @@ static void cifs_req_issue_read(struct netfs_io_subrequest *subreq)
__set_bit(NETFS_SREQ_CLEAR_TAIL, &subreq->flags);
rdata->pid = pid;
- rc = adjust_credits(rdata->server, &rdata->credits, rdata->subreq.len);
+ rc = adjust_credits(rdata->server, rdata, cifs_trace_rw_credits_issue_read_adjust);
if (!rc) {
if (rdata->req->cfile->invalidHandle)
rc = -EAGAIN;
@@ -331,6 +351,15 @@ static void cifs_free_subrequest(struct netfs_io_subrequest *subreq)
#endif
}
+ if (rdata->credits.value != 0)
+ trace_smb3_rw_credits(rdata->rreq->debug_id,
+ rdata->subreq.debug_index,
+ rdata->credits.value,
+ rdata->server ? rdata->server->credits : 0,
+ rdata->server ? rdata->server->in_flight : 0,
+ -rdata->credits.value,
+ cifs_trace_rw_credits_free_subreq);
+
add_credits_and_wake_if(rdata->server, &rdata->credits, 0);
if (rdata->have_xid)
free_xid(rdata->xid);
@@ -108,7 +108,7 @@ cifs_find_mid(struct TCP_Server_Info *server, char *buffer)
static void
cifs_add_credits(struct TCP_Server_Info *server,
- const struct cifs_credits *credits, const int optype)
+ struct cifs_credits *credits, const int optype)
{
spin_lock(&server->req_lock);
server->credits += credits->value;
@@ -66,7 +66,7 @@ change_conf(struct TCP_Server_Info *server)
static void
smb2_add_credits(struct TCP_Server_Info *server,
- const struct cifs_credits *credits, const int optype)
+ struct cifs_credits *credits, const int optype)
{
int *val, rc = -1;
int scredits, in_flight;
@@ -94,6 +94,12 @@ smb2_add_credits(struct TCP_Server_Info *server,
server->conn_id, server->hostname, *val,
add, server->in_flight);
}
+ if (credits->in_flight_check > 1) {
+ pr_warn_once("rreq R=%08x[%x] Credits not in flight\n",
+ credits->rreq_debug_id, credits->rreq_debug_index);
+ } else {
+ credits->in_flight_check = 2;
+ }
WARN_ON_ONCE(server->in_flight == 0);
server->in_flight--;
if (server->in_flight == 0 &&
@@ -283,16 +289,23 @@ smb2_wait_mtu_credits(struct TCP_Server_Info *server, size_t size,
static int
smb2_adjust_credits(struct TCP_Server_Info *server,
- struct cifs_credits *credits,
- const unsigned int payload_size)
+ struct cifs_io_subrequest *subreq,
+ unsigned int /*enum smb3_rw_credits_trace*/ trace)
{
- int new_val = DIV_ROUND_UP(payload_size, SMB2_MAX_BUFFER_SIZE);
+ struct cifs_credits *credits = &subreq->credits;
+ int new_val = DIV_ROUND_UP(subreq->subreq.len, SMB2_MAX_BUFFER_SIZE);
int scredits, in_flight;
if (!credits->value || credits->value == new_val)
return 0;
if (credits->value < new_val) {
+ trace_smb3_rw_credits(subreq->rreq->debug_id,
+ subreq->subreq.debug_index,
+ credits->value,
+ server->credits, server->in_flight,
+ new_val - credits->value,
+ cifs_trace_rw_credits_no_adjust_up);
trace_smb3_too_many_credits(server->CurrentMid,
server->conn_id, server->hostname, 0, credits->value - new_val, 0);
cifs_server_dbg(VFS, "request has less credits (%d) than required (%d)",
@@ -308,6 +321,12 @@ smb2_adjust_credits(struct TCP_Server_Info *server,
in_flight = server->in_flight;
spin_unlock(&server->req_lock);
+ trace_smb3_rw_credits(subreq->rreq->debug_id,
+ subreq->subreq.debug_index,
+ credits->value,
+ server->credits, server->in_flight,
+ new_val - credits->value,
+ cifs_trace_rw_credits_old_session);
trace_smb3_reconnect_detected(server->CurrentMid,
server->conn_id, server->hostname, scredits,
credits->value - new_val, in_flight);
@@ -316,6 +335,11 @@ smb2_adjust_credits(struct TCP_Server_Info *server,
return -EAGAIN;
}
+ trace_smb3_rw_credits(subreq->rreq->debug_id,
+ subreq->subreq.debug_index,
+ credits->value,
+ server->credits, server->in_flight,
+ new_val - credits->value, trace);
server->credits += credits->value - new_val;
scredits = server->credits;
in_flight = server->in_flight;
@@ -4494,6 +4494,8 @@ smb2_readv_callback(struct mid_q_entry *mid)
(struct smb2_hdr *)rdata->iov[0].iov_base;
struct cifs_credits credits = { .value = 0, .instance = 0 };
struct smb_rqst rqst = { .rq_iov = &rdata->iov[1], .rq_nvec = 1 };
+ unsigned int rreq_debug_id = rdata->rreq->debug_id;
+ unsigned int subreq_debug_index = rdata->subreq.debug_index;
if (rdata->got_bytes) {
rqst.rq_iter = rdata->subreq.io_iter;
@@ -4579,11 +4581,18 @@ smb2_readv_callback(struct mid_q_entry *mid)
}
if (rdata->result == 0 || rdata->result == -EAGAIN)
iov_iter_advance(&rdata->subreq.io_iter, rdata->got_bytes);
+
+ trace_smb3_rw_credits(rreq_debug_id, subreq_debug_index, rdata->credits.value,
+ server->credits, server->in_flight,
+ 0, cifs_trace_rw_credits_read_response_clear);
rdata->credits.value = 0;
netfs_subreq_terminated(&rdata->subreq,
(rdata->result == 0 || rdata->result == -EAGAIN) ?
rdata->got_bytes : rdata->result, true);
release_mid(mid);
+ trace_smb3_rw_credits(rreq_debug_id, subreq_debug_index, 0,
+ server->credits, server->in_flight,
+ credits.value, cifs_trace_rw_credits_write_response_add);
add_credits(server, &credits, 0);
}
@@ -4640,7 +4649,7 @@ smb2_async_readv(struct cifs_io_subrequest *rdata)
min_t(int, server->max_credits -
server->credits, credit_request));
- rc = adjust_credits(server, &rdata->credits, rdata->subreq.len);
+ rc = adjust_credits(server, rdata, cifs_trace_rw_credits_call_readv_adjust);
if (rc)
goto async_readv_out;
@@ -4760,6 +4769,8 @@ smb2_writev_callback(struct mid_q_entry *mid)
struct TCP_Server_Info *server = wdata->server;
struct smb2_write_rsp *rsp = (struct smb2_write_rsp *)mid->resp_buf;
struct cifs_credits credits = { .value = 0, .instance = 0 };
+ unsigned int rreq_debug_id = wdata->rreq->debug_id;
+ unsigned int subreq_debug_index = wdata->subreq.debug_index;
ssize_t result = 0;
size_t written;
@@ -4831,9 +4842,15 @@ smb2_writev_callback(struct mid_q_entry *mid)
tcon->tid, tcon->ses->Suid,
wdata->subreq.start, wdata->subreq.len);
+ trace_smb3_rw_credits(rreq_debug_id, subreq_debug_index, wdata->credits.value,
+ server->credits, server->in_flight,
+ 0, cifs_trace_rw_credits_write_response_clear);
wdata->credits.value = 0;
cifs_write_subrequest_terminated(wdata, result ?: written, true);
release_mid(mid);
+ trace_smb3_rw_credits(rreq_debug_id, subreq_debug_index, 0,
+ server->credits, server->in_flight,
+ credits.value, cifs_trace_rw_credits_write_response_add);
add_credits(server, &credits, 0);
}
@@ -4966,7 +4983,7 @@ smb2_async_writev(struct cifs_io_subrequest *wdata)
min_t(int, server->max_credits -
server->credits, credit_request));
- rc = adjust_credits(server, &wdata->credits, io_parms->length);
+ rc = adjust_credits(server, wdata, cifs_trace_rw_credits_call_writev_adjust);
if (rc)
goto async_writev_out;
@@ -4991,6 +5008,12 @@ smb2_async_writev(struct cifs_io_subrequest *wdata)
cifs_small_buf_release(req);
out:
if (rc) {
+ trace_smb3_rw_credits(wdata->rreq->debug_id,
+ wdata->subreq.debug_index,
+ wdata->credits.value,
+ server->credits, server->in_flight,
+ -(int)wdata->credits.value,
+ cifs_trace_rw_credits_write_response_clear);
add_credits_and_wake_if(wdata->server, &wdata->credits, 0);
cifs_write_subrequest_terminated(wdata, rc, true);
}
@@ -20,6 +20,21 @@
/*
* Specify enums for tracing information.
*/
+#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") \
+ EM(cifs_trace_rw_credits_free_subreq, "free-subreq") \
+ EM(cifs_trace_rw_credits_issue_read_adjust, "rd-issu-adj") \
+ EM(cifs_trace_rw_credits_issue_write_adjust, "wr-issu-adj") \
+ EM(cifs_trace_rw_credits_no_adjust_up, "no-adj-up ") \
+ EM(cifs_trace_rw_credits_old_session, "old-session") \
+ EM(cifs_trace_rw_credits_read_clamp, "rd-clamp ") \
+ EM(cifs_trace_rw_credits_read_response_add, "rd-resp-add") \
+ EM(cifs_trace_rw_credits_read_response_clear, "rd-resp-clr") \
+ EM(cifs_trace_rw_credits_write_prepare, "wr-prepare ") \
+ EM(cifs_trace_rw_credits_write_response_add, "wr-resp-add") \
+ E_(cifs_trace_rw_credits_write_response_clear, "wr-resp-clr")
+
#define smb3_tcon_ref_traces \
EM(netfs_trace_tcon_ref_dec_dfs_refer, "DEC DfsRef") \
EM(netfs_trace_tcon_ref_free, "FRE ") \
@@ -59,7 +74,8 @@
#define EM(a, b) a,
#define E_(a, b) a
-enum smb3_tcon_ref_trace { smb3_tcon_ref_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);
#undef EM
#undef E_
@@ -71,6 +87,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);
+smb3_rw_credits_traces;
smb3_tcon_ref_traces;
#undef EM
@@ -1316,6 +1333,41 @@ TRACE_EVENT(smb3_tcon_ref,
__entry->ref)
);
+TRACE_EVENT(smb3_rw_credits,
+ TP_PROTO(unsigned int rreq_debug_id,
+ unsigned int subreq_debug_index,
+ unsigned int subreq_credits,
+ unsigned int server_credits,
+ int server_in_flight,
+ int credit_change,
+ enum smb3_rw_credits_trace trace),
+ TP_ARGS(rreq_debug_id, subreq_debug_index, subreq_credits,
+ server_credits, server_in_flight, credit_change, trace),
+ TP_STRUCT__entry(
+ __field(unsigned int, rreq_debug_id)
+ __field(unsigned int, subreq_debug_index)
+ __field(unsigned int, subreq_credits)
+ __field(unsigned int, server_credits)
+ __field(int, in_flight)
+ __field(int, credit_change)
+ __field(enum smb3_rw_credits_trace, trace)
+ ),
+ TP_fast_assign(
+ __entry->rreq_debug_id = rreq_debug_id;
+ __entry->subreq_debug_index = subreq_debug_index;
+ __entry->subreq_credits = subreq_credits;
+ __entry->server_credits = server_credits;
+ __entry->in_flight = server_in_flight;
+ __entry->credit_change = credit_change;
+ __entry->trace = trace;
+ ),
+ TP_printk("R=%08x[%x] %s cred=%u chg=%d pool=%u ifl=%d",
+ __entry->rreq_debug_id, __entry->subreq_debug_index,
+ __print_symbolic(__entry->trace, smb3_rw_credits_traces),
+ __entry->subreq_credits, __entry->credit_change,
+ __entry->server_credits, __entry->in_flight)
+ );
+
#undef EM
#undef E_
@@ -988,10 +988,10 @@ static void
cifs_compound_callback(struct mid_q_entry *mid)
{
struct TCP_Server_Info *server = mid->server;
- struct cifs_credits credits;
-
- credits.value = server->ops->get_credits(mid);
- credits.instance = server->reconnect_instance;
+ struct cifs_credits credits = {
+ .value = server->ops->get_credits(mid),
+ .instance = server->reconnect_instance,
+ };
add_credits(server, &credits, mid->optype);
Add some debugging to try and work out what the cause of the add_credits() warning that generic/014 and generic/074 cause. There are two parts to this: (1) Add a tracepoint to track credits flow in read/write requests. This can be enabled with: echo 1 > /sys/kernel/debug/tracing/events/cifs/smb3_rw_credits/enable (2) Add a three-state flag to struct cifs_credits to note if we're interested in determining when the in_flight contribution ends and also note the request/subrequest details for logging in the event that we encounter a double-credit add. Signed-off-by: David Howells <dhowells@redhat.com> --- fs/smb/client/cifsglob.h | 17 ++++++++------ fs/smb/client/file.c | 33 ++++++++++++++++++++++++++-- fs/smb/client/smb1ops.c | 2 - fs/smb/client/smb2ops.c | 32 +++++++++++++++++++++++---- fs/smb/client/smb2pdu.c | 27 +++++++++++++++++++++-- fs/smb/client/trace.h | 54 +++++++++++++++++++++++++++++++++++++++++++++- fs/smb/client/transport.c | 8 +++--- 7 files changed, 152 insertions(+), 21 deletions(-)