blktrace: fix accounting of partially completed requests
authorRoman Pen <r.peniaev@gmail.com>
Tue, 4 Mar 2014 14:13:10 +0000 (23:13 +0900)
committerGreg Kroah-Hartman <gregkh@linuxfoundation.org>
Sat, 31 May 2014 04:52:11 +0000 (21:52 -0700)
commit af5040da01ef980670b3741b3e10733ee3e33566 upstream.

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
Signed-off-by: Jens Axboe <axboe@fb.com>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
block/blk-core.c
include/trace/events/block.h
kernel/trace/blktrace.c

index 2c66daba44ddd28c6c6c55b1bacd1254a4d7555b..5a750b18172e052915f3556fa41560c92ba75ea2 100644 (file)
@@ -2299,7 +2299,7 @@ bool blk_update_request(struct request *req, int error, unsigned int nr_bytes)
        if (!req->bio)
                return false;
 
        if (!req->bio)
                return false;
 
-       trace_block_rq_complete(req->q, req);
+       trace_block_rq_complete(req->q, req, nr_bytes);
 
        /*
         * For fs requests, rq is just carrier of independent bio's
 
        /*
         * For fs requests, rq is just carrier of independent bio's
index 60ae7c3db912de7e068452de1a1c1978cad0a662..2e96e2bb1529c37f3961828dfe2baf93606a22c4 100644 (file)
@@ -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
  * 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
  *
  * 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.
  */
  * 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,
 );
 
 DECLARE_EVENT_CLASS(block_rq,
index b8b8560bfb95af43d36817d743f6218f01ed0edb..686417ba5cd18ab07e7d4c70a79b9fcc54e45936 100644 (file)
@@ -685,6 +685,7 @@ void blk_trace_shutdown(struct request_queue *q)
  * blk_add_trace_rq - Add a trace for a request oriented action
  * @q:         queue the io is for
  * @rq:                the source request
  * blk_add_trace_rq - Add a trace for a request oriented action
  * @q:         queue the io is for
  * @rq:                the source request
+ * @nr_bytes:  number of completed bytes
  * @what:      the action
  *
  * Description:
  * @what:      the action
  *
  * Description:
@@ -692,7 +693,7 @@ void blk_trace_shutdown(struct request_queue *q)
  *
  **/
 static void blk_add_trace_rq(struct request_queue *q, struct request *rq,
  *
  **/
 static void blk_add_trace_rq(struct request_queue *q, struct request *rq,
-                            u32 what)
+                            unsigned int nr_bytes, u32 what)
 {
        struct blk_trace *bt = q->blk_trace;
 
 {
        struct blk_trace *bt = q->blk_trace;
 
@@ -701,11 +702,11 @@ static void blk_add_trace_rq(struct request_queue *q, struct request *rq,
 
        if (rq->cmd_type == REQ_TYPE_BLOCK_PC) {
                what |= BLK_TC_ACT(BLK_TC_PC);
 
        if (rq->cmd_type == REQ_TYPE_BLOCK_PC) {
                what |= BLK_TC_ACT(BLK_TC_PC);
-               __blk_add_trace(bt, 0, blk_rq_bytes(rq), rq->cmd_flags,
+               __blk_add_trace(bt, 0, nr_bytes, rq->cmd_flags,
                                what, rq->errors, rq->cmd_len, rq->cmd);
        } else  {
                what |= BLK_TC_ACT(BLK_TC_FS);
                                what, rq->errors, rq->cmd_len, rq->cmd);
        } else  {
                what |= BLK_TC_ACT(BLK_TC_FS);
-               __blk_add_trace(bt, blk_rq_pos(rq), blk_rq_bytes(rq),
+               __blk_add_trace(bt, blk_rq_pos(rq), nr_bytes,
                                rq->cmd_flags, what, rq->errors, 0, NULL);
        }
 }
                                rq->cmd_flags, what, rq->errors, 0, NULL);
        }
 }
@@ -713,33 +714,34 @@ static void blk_add_trace_rq(struct request_queue *q, struct request *rq,
 static void blk_add_trace_rq_abort(void *ignore,
                                   struct request_queue *q, struct request *rq)
 {
 static void blk_add_trace_rq_abort(void *ignore,
                                   struct request_queue *q, struct request *rq)
 {
-       blk_add_trace_rq(q, rq, BLK_TA_ABORT);
+       blk_add_trace_rq(q, rq, blk_rq_bytes(rq), BLK_TA_ABORT);
 }
 
 static void blk_add_trace_rq_insert(void *ignore,
                                    struct request_queue *q, struct request *rq)
 {
 }
 
 static void blk_add_trace_rq_insert(void *ignore,
                                    struct request_queue *q, struct request *rq)
 {
-       blk_add_trace_rq(q, rq, BLK_TA_INSERT);
+       blk_add_trace_rq(q, rq, blk_rq_bytes(rq), BLK_TA_INSERT);
 }
 
 static void blk_add_trace_rq_issue(void *ignore,
                                   struct request_queue *q, struct request *rq)
 {
 }
 
 static void blk_add_trace_rq_issue(void *ignore,
                                   struct request_queue *q, struct request *rq)
 {
-       blk_add_trace_rq(q, rq, BLK_TA_ISSUE);
+       blk_add_trace_rq(q, rq, blk_rq_bytes(rq), BLK_TA_ISSUE);
 }
 
 static void blk_add_trace_rq_requeue(void *ignore,
                                     struct request_queue *q,
                                     struct request *rq)
 {
 }
 
 static void blk_add_trace_rq_requeue(void *ignore,
                                     struct request_queue *q,
                                     struct request *rq)
 {
-       blk_add_trace_rq(q, rq, BLK_TA_REQUEUE);
+       blk_add_trace_rq(q, rq, blk_rq_bytes(rq), BLK_TA_REQUEUE);
 }
 
 static void blk_add_trace_rq_complete(void *ignore,
                                      struct request_queue *q,
 }
 
 static void blk_add_trace_rq_complete(void *ignore,
                                      struct request_queue *q,
-                                     struct request *rq)
+                                     struct request *rq,
+                                     unsigned int nr_bytes)
 {
 {
-       blk_add_trace_rq(q, rq, BLK_TA_COMPLETE);
+       blk_add_trace_rq(q, rq, nr_bytes, BLK_TA_COMPLETE);
 }
 
 /**
 }
 
 /**