From mboxrd@z Thu Jan  1 00:00:00 1970
Received: from eggs.gnu.org ([140.186.70.92]:55150)
	by lists.gnu.org with esmtp (Exim 4.71)
	(envelope-from <kwolf@redhat.com>) id 1Qww39-00007T-AG
	for qemu-devel@nongnu.org; Fri, 26 Aug 2011 09:02:20 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
	(envelope-from <kwolf@redhat.com>) id 1Qww34-0001a1-2n
	for qemu-devel@nongnu.org; Fri, 26 Aug 2011 09:02:19 -0400
Received: from mx1.redhat.com ([209.132.183.28]:17767)
	by eggs.gnu.org with esmtp (Exim 4.71)
	(envelope-from <kwolf@redhat.com>) id 1Qww33-0001Zt-Rv
	for qemu-devel@nongnu.org; Fri, 26 Aug 2011 09:02:14 -0400
Message-ID: <4E579A02.7090304@redhat.com>
Date: Fri, 26 Aug 2011 15:05:06 +0200
From: Kevin Wolf <kwolf@redhat.com>
MIME-Version: 1.0
References: <20110821222547.GA22046@lst.de> <20110825062544.GA30579@lst.de>
	<20110825062610.GC30639@lst.de>
In-Reply-To: <20110825062610.GC30639@lst.de>
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit
Subject: Re: [Qemu-devel] [PATCH 3/3] block: latency accounting
List-Id: <qemu-devel.nongnu.org>
List-Unsubscribe: <https://lists.nongnu.org/mailman/options/qemu-devel>,
	<mailto:qemu-devel-request@nongnu.org?subject=unsubscribe>
List-Archive: <http://lists.nongnu.org/archive/html/qemu-devel>
List-Post: <mailto:qemu-devel@nongnu.org>
List-Help: <mailto:qemu-devel-request@nongnu.org?subject=help>
List-Subscribe: <https://lists.nongnu.org/mailman/listinfo/qemu-devel>,
	<mailto:qemu-devel-request@nongnu.org?subject=subscribe>
To: Christoph Hellwig <hch@lst.de>
Cc: qemu-devel@nongnu.org

Am 25.08.2011 08:26, schrieb Christoph Hellwig:
> Account the total latency for read/write/flush requests.  This allows
> management tools to average it based on a snapshot of the nr ops
> counters and allow checking for SLAs or provide statistics.
> 
> Signed-off-by: Christoph Hellwig <hch@lst.de>
> 
> Index: qemu/block.c
> ===================================================================
> --- qemu.orig/block.c	2011-08-25 08:01:12.000000000 +0200
> +++ qemu/block.c	2011-08-25 08:03:02.908005646 +0200
> @@ -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]);

The order of READ vs. WRITE is wrong here, so read latencies show up as
wr_total_time. I can fix it locally if you agree that swapping the two
lines is the right fix.

Kevin