Add new debug tracepoints when block read and write operations finish to
be able to measure latency.

Signed-off-by: Jorge Merlino <jorge.merlino@canonical.com>
---
This patch adds debug tracepoints when block read and write operations
finish. The log includes the parameters used when the operation was
initiated so that the start and finish messages can be easily
correlated. Also the return value of the operation is logged.

This can be used to analyze latency issues with block operations.
---
 block/block-backend.c | 2 ++
 block/trace-events    | 2 ++
 2 files changed, 4 insertions(+)

diff --git a/block/block-backend.c b/block/block-backend.c
index 37ba7e9fc4..75d3cd1949 100644
--- a/block/block-backend.c
+++ b/block/block-backend.c
@@ -1364,6 +1364,7 @@ blk_co_do_preadv_part(BlockBackend *blk, int64_t offset, int64_t bytes,
 
     ret = bdrv_co_preadv_part(blk->root, offset, bytes, qiov, qiov_offset,
                               flags);
+    trace_blk_co_preadv_done(blk, bs, offset, bytes, ret);
     bdrv_dec_in_flight(bs);
     return ret;
 }
@@ -1442,6 +1443,7 @@ blk_co_do_pwritev_part(BlockBackend *blk, int64_t offset, int64_t bytes,
 
     ret = bdrv_co_pwritev_part(blk->root, offset, bytes, qiov, qiov_offset,
                                flags);
+    trace_blk_co_pwritev_done(blk, bs, offset, bytes, ret);
     bdrv_dec_in_flight(bs);
     return ret;
 }
diff --git a/block/trace-events b/block/trace-events
index 950c82d4b8..842c3fc809 100644
--- a/block/trace-events
+++ b/block/trace-events
@@ -7,6 +7,8 @@ bdrv_lock_medium(void *bs, bool locked) "bs %p locked %d"
 # block-backend.c
 blk_co_preadv(void *blk, void *bs, int64_t offset, int64_t bytes, int flags) "blk %p bs %p offset %"PRId64" bytes %" PRId64 " flags 0x%x"
 blk_co_pwritev(void *blk, void *bs, int64_t offset, int64_t bytes, int flags) "blk %p bs %p offset %"PRId64" bytes %" PRId64 " flags 0x%x"
+blk_co_preadv_done(void *blk, void *bs, int64_t offset, int64_t bytes, int ret) "blk %p bs %p offset %"PRId64" bytes %" PRId64 " ret %d"
+blk_co_pwritev_done(void *blk, void *bs, int64_t offset, int64_t bytes, int ret) "blk %p bs %p offset %"PRId64" bytes %" PRId64 " ret %d"
 blk_root_attach(void *child, void *blk, void *bs) "child %p blk %p bs %p"
 blk_root_detach(void *child, void *blk, void *bs) "child %p blk %p bs %p"
 

---
base-commit: 1df256f5968e9f7c3c4533a1383b071c044a36d6
change-id: 20260909-debug-block-ops-b4-d6e6f9ad182f

Best regards,
-- 
Jorge Merlino <jorge.merlino@canonical.com>

Am 09.09.2026 um 21:56 hat Jorge Merlino geschrieben:
> Add new debug tracepoints when block read and write operations finish to
> be able to measure latency.
> 
> Signed-off-by: Jorge Merlino <jorge.merlino@canonical.com>

The subject line should mention trace points. Maybe just "block: Add
tracepoiont at end of read/write"?

> This patch adds debug tracepoints when block read and write operations
> finish. The log includes the parameters used when the operation was
> initiated so that the start and finish messages can be easily
> correlated. Also the return value of the operation is logged.
> 
> This can be used to analyze latency issues with block operations.

Yes, this seems useful.

I wonder if we shouldn't make sure that the start and end traces always
come in pairs. Specifically...

>  block/block-backend.c | 2 ++
>  block/trace-events    | 2 ++
>  2 files changed, 4 insertions(+)
> 
> diff --git a/block/block-backend.c b/block/block-backend.c
> index 37ba7e9fc4..75d3cd1949 100644
> --- a/block/block-backend.c
> +++ b/block/block-backend.c
> @@ -1364,6 +1364,7 @@ blk_co_do_preadv_part(BlockBackend *blk, int64_t offset, int64_t bytes,

Adding more context here:

    trace_blk_co_preadv(blk, bs, offset, bytes, flags);

    ret = blk_check_byte_request(blk, offset, bytes);
    if (ret < 0) {
        return ret;
    }

Should this error return also call trace_blk_co_preadv_done()?

    bdrv_inc_in_flight(bs);

    /* throttling disk I/O */
    if (qatomic_load_acquire(&tgm->throttle_state)) {
        throttle_group_co_io_limits_intercept(tgm, bytes, THROTTLE_READ);
    }

>  
>      ret = bdrv_co_preadv_part(blk->root, offset, bytes, qiov, qiov_offset,
>                                flags);
> +    trace_blk_co_preadv_done(blk, bs, offset, bytes, ret);
>      bdrv_dec_in_flight(bs);
>      return ret;
>  }
> @@ -1442,6 +1443,7 @@ blk_co_do_pwritev_part(BlockBackend *blk, int64_t offset, int64_t bytes,
>  
>      ret = bdrv_co_pwritev_part(blk->root, offset, bytes, qiov, qiov_offset,
>                                 flags);
> +    trace_blk_co_pwritev_done(blk, bs, offset, bytes, ret);
>      bdrv_dec_in_flight(bs);
>      return ret;
>  }

Same question for writes.

Kevin