Skip to content

Commit 90b3ccf

Browse files
dhowellsbrauner
authored andcommitted
netfs: Update tracepoints in a number of ways
Make a number of updates to the netfs tracepoints: (1) Remove a duplicate trace from netfs_unbuffered_write_iter_locked(). (2) Move the trace in netfs_wake_rreq_flag() to after the flag is cleared so that the change appears in the trace. (3) Differentiate the use of netfs_rreq_trace_wait/woke_queue symbols. (4) Don't do so many trace emissions in the wait functions as some of them are redundant. (5) In netfs_collect_read_results(), differentiate a subreq that's being abandoned vs one that has been consumed in a regular way. (6) Add a tracepoint to indicate the call to ->ki_complete(). (7) Don't double-increment the subreq_counter when retrying a write. (8) Move the netfs_sreq_trace_io_progress tracepoint within cifs code to just MID_RESPONSE_RECEIVED and add different tracepoints for other MID states and note check failure. Signed-off-by: David Howells <[email protected]> Co-developed-by: Paulo Alcantara <[email protected]> Signed-off-by: Paulo Alcantara <[email protected]> Link: https://lore.kernel.org/[email protected] cc: Steve French <[email protected]> cc: [email protected] cc: [email protected] cc: [email protected] Signed-off-by: Christian Brauner <[email protected]>
1 parent 4e32541 commit 90b3ccf

File tree

9 files changed

+79
-27
lines changed

9 files changed

+79
-27
lines changed

fs/netfs/direct_write.c

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -91,7 +91,6 @@ ssize_t netfs_unbuffered_write_iter_locked(struct kiocb *iocb, struct iov_iter *
9191
}
9292

9393
if (!async) {
94-
trace_netfs_rreq(wreq, netfs_rreq_trace_wait_ip);
9594
ret = netfs_wait_for_write(wreq);
9695
if (ret > 0)
9796
iocb->ki_pos += ret;

fs/netfs/internal.h

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -273,9 +273,9 @@ static inline void netfs_wake_rreq_flag(struct netfs_io_request *rreq,
273273
enum netfs_rreq_trace trace)
274274
{
275275
if (test_bit(rreq_flag, &rreq->flags)) {
276-
trace_netfs_rreq(rreq, trace);
277276
clear_bit_unlock(rreq_flag, &rreq->flags);
278277
smp_mb__after_atomic(); /* Set flag before task state */
278+
trace_netfs_rreq(rreq, trace);
279279
wake_up(&rreq->waitq);
280280
}
281281
}

fs/netfs/misc.c

Lines changed: 6 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -359,7 +359,7 @@ void netfs_wait_for_in_progress_stream(struct netfs_io_request *rreq,
359359
if (!netfs_check_subreq_in_progress(subreq))
360360
continue;
361361

362-
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_queue);
362+
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_quiesce);
363363
for (;;) {
364364
prepare_to_wait(&rreq->waitq, &myself, TASK_UNINTERRUPTIBLE);
365365

@@ -368,10 +368,10 @@ void netfs_wait_for_in_progress_stream(struct netfs_io_request *rreq,
368368

369369
trace_netfs_sreq(subreq, netfs_sreq_trace_wait_for);
370370
schedule();
371-
trace_netfs_rreq(rreq, netfs_rreq_trace_woke_queue);
372371
}
373372
}
374373

374+
trace_netfs_rreq(rreq, netfs_rreq_trace_waited_quiesce);
375375
finish_wait(&rreq->waitq, &myself);
376376
}
377377

@@ -437,7 +437,6 @@ static ssize_t netfs_wait_for_in_progress(struct netfs_io_request *rreq,
437437
ssize_t ret;
438438

439439
for (;;) {
440-
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_queue);
441440
prepare_to_wait(&rreq->waitq, &myself, TASK_UNINTERRUPTIBLE);
442441

443442
if (!test_bit(NETFS_RREQ_OFFLOAD_COLLECTION, &rreq->flags)) {
@@ -457,11 +456,12 @@ static ssize_t netfs_wait_for_in_progress(struct netfs_io_request *rreq,
457456
if (!netfs_check_rreq_in_progress(rreq))
458457
break;
459458

459+
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_ip);
460460
schedule();
461-
trace_netfs_rreq(rreq, netfs_rreq_trace_woke_queue);
462461
}
463462

464463
all_collected:
464+
trace_netfs_rreq(rreq, netfs_rreq_trace_waited_ip);
465465
finish_wait(&rreq->waitq, &myself);
466466

467467
ret = rreq->error;
@@ -504,10 +504,8 @@ static void netfs_wait_for_pause(struct netfs_io_request *rreq,
504504
{
505505
DEFINE_WAIT(myself);
506506

507-
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_pause);
508-
509507
for (;;) {
510-
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_queue);
508+
trace_netfs_rreq(rreq, netfs_rreq_trace_wait_pause);
511509
prepare_to_wait(&rreq->waitq, &myself, TASK_UNINTERRUPTIBLE);
512510

513511
if (!test_bit(NETFS_RREQ_OFFLOAD_COLLECTION, &rreq->flags)) {
@@ -530,10 +528,10 @@ static void netfs_wait_for_pause(struct netfs_io_request *rreq,
530528
break;
531529

532530
schedule();
533-
trace_netfs_rreq(rreq, netfs_rreq_trace_woke_queue);
534531
}
535532

536533
all_collected:
534+
trace_netfs_rreq(rreq, netfs_rreq_trace_waited_pause);
537535
finish_wait(&rreq->waitq, &myself);
538536
}
539537

fs/netfs/read_collect.c

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -293,7 +293,9 @@ static void netfs_collect_read_results(struct netfs_io_request *rreq)
293293
spin_lock(&rreq->lock);
294294

295295
remove = front;
296-
trace_netfs_sreq(front, netfs_sreq_trace_discard);
296+
trace_netfs_sreq(front,
297+
notes & ABANDON_SREQ ?
298+
netfs_sreq_trace_abandoned : netfs_sreq_trace_consumed);
297299
list_del_init(&front->rreq_link);
298300
front = list_first_entry_or_null(&stream->subrequests,
299301
struct netfs_io_subrequest, rreq_link);
@@ -353,9 +355,11 @@ static void netfs_rreq_assess_dio(struct netfs_io_request *rreq)
353355

354356
if (rreq->iocb) {
355357
rreq->iocb->ki_pos += rreq->transferred;
356-
if (rreq->iocb->ki_complete)
358+
if (rreq->iocb->ki_complete) {
359+
trace_netfs_rreq(rreq, netfs_rreq_trace_ki_complete);
357360
rreq->iocb->ki_complete(
358361
rreq->iocb, rreq->error ? rreq->error : rreq->transferred);
362+
}
359363
}
360364
if (rreq->netfs_ops->done)
361365
rreq->netfs_ops->done(rreq);
@@ -379,9 +383,11 @@ static void netfs_rreq_assess_single(struct netfs_io_request *rreq)
379383

380384
if (rreq->iocb) {
381385
rreq->iocb->ki_pos += rreq->transferred;
382-
if (rreq->iocb->ki_complete)
386+
if (rreq->iocb->ki_complete) {
387+
trace_netfs_rreq(rreq, netfs_rreq_trace_ki_complete);
383388
rreq->iocb->ki_complete(
384389
rreq->iocb, rreq->error ? rreq->error : rreq->transferred);
390+
}
385391
}
386392
if (rreq->netfs_ops->done)
387393
rreq->netfs_ops->done(rreq);

fs/netfs/write_collect.c

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -421,9 +421,11 @@ bool netfs_write_collection(struct netfs_io_request *wreq)
421421
if (wreq->iocb) {
422422
size_t written = min(wreq->transferred, wreq->len);
423423
wreq->iocb->ki_pos += written;
424-
if (wreq->iocb->ki_complete)
424+
if (wreq->iocb->ki_complete) {
425+
trace_netfs_rreq(wreq, netfs_rreq_trace_ki_complete);
425426
wreq->iocb->ki_complete(
426427
wreq->iocb, wreq->error ? wreq->error : written);
428+
}
427429
wreq->iocb = VFS_PTR_POISON;
428430
}
429431

fs/netfs/write_retry.c

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -146,7 +146,6 @@ static void netfs_retry_write_stream(struct netfs_io_request *wreq,
146146
subreq = netfs_alloc_subrequest(wreq);
147147
subreq->source = to->source;
148148
subreq->start = start;
149-
subreq->debug_index = atomic_inc_return(&wreq->subreq_counter);
150149
subreq->stream_nr = to->stream_nr;
151150
subreq->retry_count = 1;
152151

fs/smb/client/cifssmb.c

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1334,7 +1334,11 @@ cifs_readv_callback(struct mid_q_entry *mid)
13341334
cifs_stats_bytes_read(tcon, rdata->got_bytes);
13351335
break;
13361336
case MID_REQUEST_SUBMITTED:
1337+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_req_submitted);
1338+
goto do_retry;
13371339
case MID_RETRY_NEEDED:
1340+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_retry_needed);
1341+
do_retry:
13381342
__set_bit(NETFS_SREQ_NEED_RETRY, &rdata->subreq.flags);
13391343
rdata->result = -EAGAIN;
13401344
if (server->sign && rdata->got_bytes)
@@ -1344,8 +1348,14 @@ cifs_readv_callback(struct mid_q_entry *mid)
13441348
task_io_account_read(rdata->got_bytes);
13451349
cifs_stats_bytes_read(tcon, rdata->got_bytes);
13461350
break;
1351+
case MID_RESPONSE_MALFORMED:
1352+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_malformed);
1353+
rdata->result = -EIO;
1354+
break;
13471355
default:
1356+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_unknown);
13481357
rdata->result = -EIO;
1358+
break;
13491359
}
13501360

13511361
if (rdata->result == -ENODATA) {
@@ -1714,11 +1724,21 @@ cifs_writev_callback(struct mid_q_entry *mid)
17141724
}
17151725
break;
17161726
case MID_REQUEST_SUBMITTED:
1727+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_req_submitted);
1728+
__set_bit(NETFS_SREQ_NEED_RETRY, &wdata->subreq.flags);
1729+
result = -EAGAIN;
1730+
break;
17171731
case MID_RETRY_NEEDED:
1732+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_retry_needed);
17181733
__set_bit(NETFS_SREQ_NEED_RETRY, &wdata->subreq.flags);
17191734
result = -EAGAIN;
17201735
break;
1736+
case MID_RESPONSE_MALFORMED:
1737+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_malformed);
1738+
result = -EIO;
1739+
break;
17211740
default:
1741+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_unknown);
17221742
result = -EIO;
17231743
break;
17241744
}

fs/smb/client/smb2pdu.c

Lines changed: 22 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -4567,7 +4567,11 @@ smb2_readv_callback(struct mid_q_entry *mid)
45674567
cifs_stats_bytes_read(tcon, rdata->got_bytes);
45684568
break;
45694569
case MID_REQUEST_SUBMITTED:
4570+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_req_submitted);
4571+
goto do_retry;
45704572
case MID_RETRY_NEEDED:
4573+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_retry_needed);
4574+
do_retry:
45714575
__set_bit(NETFS_SREQ_NEED_RETRY, &rdata->subreq.flags);
45724576
rdata->result = -EAGAIN;
45734577
if (server->sign && rdata->got_bytes)
@@ -4578,11 +4582,15 @@ smb2_readv_callback(struct mid_q_entry *mid)
45784582
cifs_stats_bytes_read(tcon, rdata->got_bytes);
45794583
break;
45804584
case MID_RESPONSE_MALFORMED:
4585+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_malformed);
45814586
credits.value = le16_to_cpu(shdr->CreditRequest);
45824587
credits.instance = server->reconnect_instance;
4583-
fallthrough;
4588+
rdata->result = -EIO;
4589+
break;
45844590
default:
4591+
trace_netfs_sreq(&rdata->subreq, netfs_sreq_trace_io_unknown);
45854592
rdata->result = -EIO;
4593+
break;
45864594
}
45874595
#ifdef CONFIG_CIFS_SMB_DIRECT
45884596
/*
@@ -4835,11 +4843,14 @@ smb2_writev_callback(struct mid_q_entry *mid)
48354843

48364844
switch (mid->mid_state) {
48374845
case MID_RESPONSE_RECEIVED:
4846+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_progress);
48384847
credits.value = le16_to_cpu(rsp->hdr.CreditRequest);
48394848
credits.instance = server->reconnect_instance;
48404849
result = smb2_check_receive(mid, server, 0);
4841-
if (result != 0)
4850+
if (result != 0) {
4851+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_bad);
48424852
break;
4853+
}
48434854

48444855
written = le32_to_cpu(rsp->DataLength);
48454856
/*
@@ -4861,15 +4872,23 @@ smb2_writev_callback(struct mid_q_entry *mid)
48614872
}
48624873
break;
48634874
case MID_REQUEST_SUBMITTED:
4875+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_req_submitted);
4876+
__set_bit(NETFS_SREQ_NEED_RETRY, &wdata->subreq.flags);
4877+
result = -EAGAIN;
4878+
break;
48644879
case MID_RETRY_NEEDED:
4880+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_retry_needed);
48654881
__set_bit(NETFS_SREQ_NEED_RETRY, &wdata->subreq.flags);
48664882
result = -EAGAIN;
48674883
break;
48684884
case MID_RESPONSE_MALFORMED:
4885+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_malformed);
48694886
credits.value = le16_to_cpu(rsp->hdr.CreditRequest);
48704887
credits.instance = server->reconnect_instance;
4871-
fallthrough;
4888+
result = -EIO;
4889+
break;
48724890
default:
4891+
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_unknown);
48734892
result = -EIO;
48744893
break;
48754894
}
@@ -4909,7 +4928,6 @@ smb2_writev_callback(struct mid_q_entry *mid)
49094928
server->credits, server->in_flight,
49104929
0, cifs_trace_rw_credits_write_response_clear);
49114930
wdata->credits.value = 0;
4912-
trace_netfs_sreq(&wdata->subreq, netfs_sreq_trace_io_progress);
49134931
cifs_write_subrequest_terminated(wdata, result ?: written);
49144932
release_mid(mid);
49154933
trace_smb3_rw_credits(rreq_debug_id, subreq_debug_index, 0,

include/trace/events/netfs.h

Lines changed: 18 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -50,12 +50,13 @@
5050

5151
#define netfs_rreq_traces \
5252
EM(netfs_rreq_trace_assess, "ASSESS ") \
53-
EM(netfs_rreq_trace_copy, "COPY ") \
5453
EM(netfs_rreq_trace_collect, "COLLECT") \
5554
EM(netfs_rreq_trace_complete, "COMPLET") \
55+
EM(netfs_rreq_trace_copy, "COPY ") \
5656
EM(netfs_rreq_trace_dirty, "DIRTY ") \
5757
EM(netfs_rreq_trace_done, "DONE ") \
5858
EM(netfs_rreq_trace_free, "FREE ") \
59+
EM(netfs_rreq_trace_ki_complete, "KI-CMPL") \
5960
EM(netfs_rreq_trace_recollect, "RECLLCT") \
6061
EM(netfs_rreq_trace_redirty, "REDIRTY") \
6162
EM(netfs_rreq_trace_resubmit, "RESUBMT") \
@@ -64,13 +65,15 @@
6465
EM(netfs_rreq_trace_unlock, "UNLOCK ") \
6566
EM(netfs_rreq_trace_unlock_pgpriv2, "UNLCK-2") \
6667
EM(netfs_rreq_trace_unmark, "UNMARK ") \
68+
EM(netfs_rreq_trace_unpause, "UNPAUSE") \
6769
EM(netfs_rreq_trace_wait_ip, "WAIT-IP") \
68-
EM(netfs_rreq_trace_wait_pause, "WT-PAUS") \
69-
EM(netfs_rreq_trace_wait_queue, "WAIT-Q ") \
70+
EM(netfs_rreq_trace_wait_pause, "--PAUSED--") \
71+
EM(netfs_rreq_trace_wait_quiesce, "WAIT-QUIESCE") \
72+
EM(netfs_rreq_trace_waited_ip, "DONE-IP") \
73+
EM(netfs_rreq_trace_waited_pause, "--UNPAUSED--") \
74+
EM(netfs_rreq_trace_waited_quiesce, "DONE-QUIESCE") \
7075
EM(netfs_rreq_trace_wake_ip, "WAKE-IP") \
7176
EM(netfs_rreq_trace_wake_queue, "WAKE-Q ") \
72-
EM(netfs_rreq_trace_woke_queue, "WOKE-Q ") \
73-
EM(netfs_rreq_trace_unpause, "UNPAUSE") \
7477
E_(netfs_rreq_trace_write_done, "WR-DONE")
7578

7679
#define netfs_sreq_sources \
@@ -83,21 +86,28 @@
8386
E_(NETFS_WRITE_TO_CACHE, "WRIT")
8487

8588
#define netfs_sreq_traces \
89+
EM(netfs_sreq_trace_abandoned, "ABNDN") \
8690
EM(netfs_sreq_trace_add_donations, "+DON ") \
8791
EM(netfs_sreq_trace_added, "ADD ") \
8892
EM(netfs_sreq_trace_cache_nowrite, "CA-NW") \
8993
EM(netfs_sreq_trace_cache_prepare, "CA-PR") \
9094
EM(netfs_sreq_trace_cache_write, "CA-WR") \
9195
EM(netfs_sreq_trace_cancel, "CANCL") \
9296
EM(netfs_sreq_trace_clear, "CLEAR") \
97+
EM(netfs_sreq_trace_consumed, "CONSM") \
9398
EM(netfs_sreq_trace_discard, "DSCRD") \
9499
EM(netfs_sreq_trace_donate_to_prev, "DON-P") \
95100
EM(netfs_sreq_trace_donate_to_next, "DON-N") \
96101
EM(netfs_sreq_trace_download_instead, "RDOWN") \
97102
EM(netfs_sreq_trace_fail, "FAIL ") \
98103
EM(netfs_sreq_trace_free, "FREE ") \
99104
EM(netfs_sreq_trace_hit_eof, "EOF ") \
100-
EM(netfs_sreq_trace_io_progress, "IO ") \
105+
EM(netfs_sreq_trace_io_bad, "I-BAD") \
106+
EM(netfs_sreq_trace_io_malformed, "I-MLF") \
107+
EM(netfs_sreq_trace_io_unknown, "I-UNK") \
108+
EM(netfs_sreq_trace_io_progress, "I-OK ") \
109+
EM(netfs_sreq_trace_io_req_submitted, "I-RSB") \
110+
EM(netfs_sreq_trace_io_retry_needed, "I-RTR") \
101111
EM(netfs_sreq_trace_limited, "LIMIT") \
102112
EM(netfs_sreq_trace_need_clear, "N-CLR") \
103113
EM(netfs_sreq_trace_partial_read, "PARTR") \
@@ -143,8 +153,8 @@
143153

144154
#define netfs_sreq_ref_traces \
145155
EM(netfs_sreq_trace_get_copy_to_cache, "GET COPY2C ") \
146-
EM(netfs_sreq_trace_get_resubmit, "GET RESUBMIT") \
147-
EM(netfs_sreq_trace_get_submit, "GET SUBMIT") \
156+
EM(netfs_sreq_trace_get_resubmit, "GET RESUBMT") \
157+
EM(netfs_sreq_trace_get_submit, "GET SUBMIT ") \
148158
EM(netfs_sreq_trace_get_short_read, "GET SHORTRD") \
149159
EM(netfs_sreq_trace_new, "NEW ") \
150160
EM(netfs_sreq_trace_put_abandon, "PUT ABANDON") \

0 commit comments

Comments
 (0)