[3/3] block: latency accounting

Index: qemu/block.c
===================================================================
--- qemu.orig/block.c	2011-08-11 07:05:24.000000000 -0700
+++ qemu/block.c	2011-08-11 07:37:01.114924279 -0700
@@ -1889,12 +1889,18 @@  static void bdrv_stats_iter(QObject *dat
                         " rd_operations=%" PRId64
                         " wr_operations=%" PRId64
                         " flush_operations=%" PRId64
+                        " wr_total_time_ns=%" PRId64
+                        " rd_total_time_ns=%" PRId64
+                        " flush_total_time_ns=%" PRId64
                         "\n",
                         qdict_get_int(qdict, "rd_bytes"),
                         qdict_get_int(qdict, "wr_bytes"),
                         qdict_get_int(qdict, "rd_operations"),
                         qdict_get_int(qdict, "wr_operations"),
-                        qdict_get_int(qdict, "flush_operations"));
+                        qdict_get_int(qdict, "flush_operations"),
+                        qdict_get_int(qdict, "wr_total_time_ns"),
+                        qdict_get_int(qdict, "rd_total_time_ns"),
+                        qdict_get_int(qdict, "flush_total_time_ns"));
 }
 
 void bdrv_stats_print(Monitor *mon, const QObject *data)
@@ -1913,7 +1919,10 @@  static QObject* bdrv_info_stats_bs(Block
                              "'rd_operations': %" PRId64 ","
                              "'wr_operations': %" PRId64 ","
                              "'wr_highest_offset': %" PRId64 ","
-                             "'flush_operations': %" PRId64
+                             "'flush_operations': %" PRId64 ","
+                             "'wr_total_time_ns': %" PRId64 ","
+                             "'rd_total_time_ns': %" PRId64 ","
+                             "'flush_total_time_ns': %" PRId64
                              "} }",
                              bs->nr_bytes[BDRV_ACCT_READ],
                              bs->nr_bytes[BDRV_ACCT_WRITE],
@@ -1921,7 +1930,10 @@  static QObject* bdrv_info_stats_bs(Block
                              bs->nr_ops[BDRV_ACCT_WRITE],
                              bs->wr_highest_sector *
                              (uint64_t)BDRV_SECTOR_SIZE,
-                             bs->nr_ops[BDRV_ACCT_FLUSH]);
+                             bs->nr_ops[BDRV_ACCT_FLUSH],
+                             bs->total_time_ns[BDRV_ACCT_READ],
+                             bs->total_time_ns[BDRV_ACCT_WRITE],
+                             bs->total_time_ns[BDRV_ACCT_FLUSH]);
     dict  = qobject_to_qdict(res);
 
     if (*bs->device_name) {
Index: qemu/block_int.h
===================================================================
--- qemu.orig/block_int.h	2011-08-11 07:05:24.000000000 -0700
+++ qemu/block_int.h	2011-08-11 07:37:17.964832995 -0700
@@ -28,6 +28,7 @@ 
 #include "qemu-option.h"
 #include "qemu-queue.h"
 #include "qemu-coroutine.h"
+#include "qemu-timer.h"
 
 #define BLOCK_FLAG_ENCRYPT	1
 #define BLOCK_FLAG_COMPAT6	4
@@ -193,6 +194,7 @@  struct BlockDriverState {
     /* I/O stats (display with "info blockstats"). */
     uint64_t nr_bytes[BDRV_MAX_IOTYPE];
     uint64_t nr_ops[BDRV_MAX_IOTYPE];
+    uint64_t total_time_ns[BDRV_MAX_IOTYPE];
     uint64_t wr_highest_sector;
 
     /* Whether the disk can expand beyond total_sectors */
@@ -218,6 +220,7 @@  struct BlockDriverState {
 
 typedef struct BlockAcctCookie {
     int64_t bytes;
+    int64_t start_time_ns;
     enum BlockIOType type;
 } BlockAcctCookie;
 
@@ -227,6 +230,7 @@  bdrv_acct_start(BlockDriverState *bs, Bl
 {
     cookie->bytes = bytes;
     cookie->type = type;
+    cookie->start_time_ns = get_clock();
 }
 
 static inline void
@@ -234,6 +238,7 @@  bdrv_acct_done(BlockDriverState *bs, Blo
 {
     bs->nr_bytes[cookie->type] += cookie->bytes;
     bs->nr_ops[cookie->type]++;
+    bs->total_time_ns[cookie->type] += get_clock() - cookie->start_time_ns;
 }
 
 
Index: qemu/qmp-commands.hx
===================================================================
--- qemu.orig/qmp-commands.hx	2011-08-11 07:04:48.000000000 -0700
+++ qemu/qmp-commands.hx	2011-08-11 07:37:01.121590911 -0700
@@ -1202,6 +1202,9 @@  Each json-object contain the following:
     - "rd_operations": read operations (json-int)
     - "wr_operations": write operations (json-int)
     - "flush_operations": cache flush operations (json-int)
+    - "wr_total_time_ns": total time spend on writes in nano-seconds (json-int)
+    - "rd_total_time_ns": total time spend on reads in nano-seconds (json-int)
+    - "flush_total_time_ns": total time spend on cache flushes in nano-seconds (json-int)
     - "wr_highest_offset": Highest offset of a sector written since the
                            BlockDriverState has been opened (json-int)
 - "parent": Contains recursively the statistics of the underlying
@@ -1223,6 +1226,9 @@  Example:
                   "wr_operations":751,
                   "rd_bytes":122567168,
                   "rd_operations":36772
+                  "wr_total_times_ns":313253456
+                  "rd_total_times_ns":3465673657
+                  "flush_total_times_ns":49653
                   "flush_operations":61,
                }
             },
@@ -1233,6 +1239,9 @@  Example:
                "rd_bytes":122739200,
                "rd_operations":36604
                "flush_operations":51,
+               "wr_total_times_ns":313253456
+               "rd_total_times_ns":3465673657
+               "flush_total_times_ns":49653
             }
          },
          {
@@ -1244,6 +1253,9 @@  Example:
                "rd_bytes":0,
                "rd_operations":0
                "flush_operations":0,
+               "wr_total_times_ns":0
+               "rd_total_times_ns":0
+               "flush_total_times_ns":0
             }
          },
          {
@@ -1255,6 +1267,9 @@  Example:
                "rd_bytes":0,
                "rd_operations":0
                "flush_operations":0,
+               "wr_total_times_ns":0
+               "rd_total_times_ns":0
+               "flush_total_times_ns":0
             }
          },
          {
@@ -1266,6 +1281,9 @@  Example:
                "rd_bytes":0,
                "rd_operations":0
                "flush_operations":0,
+               "wr_total_times_ns":0
+               "rd_total_times_ns":0
+               "flush_total_times_ns":0
             }
          }
       ]