blktrace: fix accounting of partially completed requests

trace_block_rq_complete does not take into account that request can
be partially completed, so we can get the following incorrect output
of blkparser:

  C   R 232 + 240 [0]
  C   R 240 + 232 [0]
  C   R 248 + 224 [0]
  C   R 256 + 216 [0]

but should be:

  C   R 232 + 8 [0]
  C   R 240 + 8 [0]
  C   R 248 + 8 [0]
  C   R 256 + 8 [0]

Also, the whole output summary statistics of completed requests and
final throughput will be incorrect.

This patch takes into account real completion size of the request and
fixes wrong completion accounting.

Signed-off-by: Roman Pen <r.peniaev@gmail.com>
CC: Steven Rostedt <rostedt@goodmis.org>
CC: Frederic Weisbecker <fweisbec@gmail.com>
CC: Ingo Molnar <mingo@redhat.com>
CC: linux-kernel@vger.kernel.org
Cc: stable@kernel.org
Signed-off-by: Jens Axboe <axboe@fb.com>

1 files changed, 30 insertions, 3 deletions

diff --git a/include/trace/events/block.h b/include/trace/events/block.h
index e76ae19a8d6f..e8a5eca1dbe5 100644
--- a/include/trace/events/block.h
+++ b/include/trace/events/block.h
@@ -132,6 +132,7 @@ DEFINE_EVENT(block_rq_with_error, block_rq_requeue,
  * block_rq_complete - block IO operation completed by device driver
  * @q: queue containing the block operation request
  * @rq: block operations request
+ * @nr_bytes: number of completed bytes
  *
  * The block_rq_complete tracepoint event indicates that some portion
  * of operation request has been completed by the device driver.  If
@@ -139,11 +140,37 @@ DEFINE_EVENT(block_rq_with_error, block_rq_requeue,
  * do for the request. If @rq->bio is non-NULL then there is
  * additional work required to complete the request.
  */
-DEFINE_EVENT(block_rq_with_error, block_rq_complete,
+TRACE_EVENT(block_rq_complete,
 
-        TP_PROTO(struct request_queue *q, struct request *rq),
+        TP_PROTO(struct request_queue *q, struct request *rq,
+                 unsigned int nr_bytes),
 
-        TP_ARGS(q, rq)
+        TP_ARGS(q, rq, nr_bytes),
+
+        TP_STRUCT__entry(
+                __field(  dev_t,        dev                     )
+                __field(  sector_t,     sector                  )
+                __field(  unsigned int, nr_sector               )
+                __field(  int,          errors                  )
+                __array(  char,         rwbs,   RWBS_LEN        )
+                __dynamic_array( char,  cmd,    blk_cmd_buf_len(rq)     )
+        ),
+
+        TP_fast_assign(
+                __entry->dev       = rq->rq_disk ? disk_devt(rq->rq_disk) : 0;
+                __entry->sector    = blk_rq_pos(rq);
+                __entry->nr_sector = nr_bytes >> 9;
+                __entry->errors    = rq->errors;
+
+                blk_fill_rwbs(__entry->rwbs, rq->cmd_flags, nr_bytes);
+                blk_dump_cmd(__get_str(cmd), rq);
+        ),
+
+        TP_printk("%d,%d %s (%s) %llu + %u [%d]",
+                  MAJOR(__entry->dev), MINOR(__entry->dev),
+                  __entry->rwbs, __get_str(cmd),
+                  (unsigned long long)__entry->sector,
+                  __entry->nr_sector, __entry->errors)
 );
 
 DECLARE_EVENT_CLASS(block_rq,