[Qemu-devel] [PATCH 0/4] block: Convert from DPRINTF() macro to trace event

[Qemu-devel] [PATCH 0/4] block: Convert from DPRINTF() macro to trace event

[Laurent Vivier]

Convert all the remaining uses of DPRINTF() in the directory block.

Compiled for all target but only tested with "make check"

Laurent Vivier (4):
  block/ssh: Convert from DPRINTF() macro to trace events
  block/curl: Convert from DPRINTF() macro to trace events
  block/file-posix: Convert from DPRINTF() macro to trace events
  block/sheepdog: Convert from DPRINTF() macro to trace events

 block/curl.c       | 29 ++++++++--------------------
 block/file-posix.c | 25 ++++++------------------
 block/sheepdog.c   | 47 +++++++++++++++++-----------------------------
 block/ssh.c        | 46 +++++++++++++++++----------------------------
 block/trace-events | 47 ++++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 95 insertions(+), 99 deletions(-)

-- 
2.19.2

[Qemu-devel] [PATCH 1/4] block/ssh: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
---
 block/ssh.c        | 46 +++++++++++++++++-----------------------------
 block/trace-events | 17 +++++++++++++++++
 2 files changed, 34 insertions(+), 29 deletions(-)

diff --git a/block/ssh.c b/block/ssh.c
index 7fbc27abdf..bbc513e095 100644
--- a/block/ssh.c
+++ b/block/ssh.c
@@ -41,27 +41,17 @@
 #include "qapi/qmp/qstring.h"
 #include "qapi/qobject-input-visitor.h"
 #include "qapi/qobject-output-visitor.h"
+#include "trace.h"
 
-/* DEBUG_SSH=1 enables the DPRINTF (debugging printf) statements in
- * this block driver code.
- *
+/*
  * TRACE_LIBSSH2=<bitmask> enables tracing in libssh2 itself.  Note
  * that this requires that libssh2 was specially compiled with the
  * `./configure --enable-debug' option, so most likely you will have
  * to compile it yourself.  The meaning of <bitmask> is described
  * here: http://www.libssh2.org/libssh2_trace.html
  */
-#define DEBUG_SSH     0
 #define TRACE_LIBSSH2 0 /* or try: LIBSSH2_TRACE_SFTP */
 
-#define DPRINTF(fmt, ...)                           \
-    do {                                            \
-        if (DEBUG_SSH) {                            \
-            fprintf(stderr, "ssh: %-15s " fmt "\n", \
-                    __func__, ##__VA_ARGS__);       \
-        }                                           \
-    } while (0)
-
 typedef struct BDRVSSHState {
     /* Coroutine. */
     CoMutex lock;
@@ -336,7 +326,7 @@ static int check_host_key_knownhosts(BDRVSSHState *s,
     switch (r) {
     case LIBSSH2_KNOWNHOST_CHECK_MATCH:
         /* OK */
-        DPRINTF("host key OK: %s", found->key);
+        trace_ssh_check_host_key_knownhosts(found->key);
         break;
     case LIBSSH2_KNOWNHOST_CHECK_MISMATCH:
         ret = -EINVAL;
@@ -721,8 +711,7 @@ static int connect_to_ssh(BDRVSSHState *s, BlockdevOptionsSsh *opts,
     }
 
     /* Open the remote file. */
-    DPRINTF("opening file %s flags=0x%x creat_mode=0%o",
-            opts->path, ssh_flags, creat_mode);
+    trace_ssh_connect_to_ssh(opts->path, ssh_flags, creat_mode);
     s->sftp_handle = libssh2_sftp_open(s->sftp, opts->path, ssh_flags,
                                        creat_mode);
     if (!s->sftp_handle) {
@@ -890,7 +879,7 @@ static int coroutine_fn ssh_co_create_opts(const char *filename, QemuOpts *opts,
     /* Get desired file size. */
     ssh_opts->size = ROUND_UP(qemu_opt_get_size_del(opts, BLOCK_OPT_SIZE, 0),
                               BDRV_SECTOR_SIZE);
-    DPRINTF("total_size=%" PRIi64, ssh_opts->size);
+    trace_ssh_co_create_opts(ssh_opts->size);
 
     uri_options = qdict_new();
     ret = parse_uri(filename, uri_options, errp);
@@ -946,7 +935,7 @@ static void restart_coroutine(void *opaque)
     BDRVSSHState *s = bs->opaque;
     AioContext *ctx = bdrv_get_aio_context(bs);
 
-    DPRINTF("co=%p", restart->co);
+    trace_ssh_restart_coroutine(restart->co);
     aio_set_fd_handler(ctx, s->sock, false, NULL, NULL, NULL, NULL);
 
     aio_co_wake(restart->co);
@@ -974,13 +963,12 @@ static coroutine_fn void co_yield(BDRVSSHState *s, BlockDriverState *bs)
         wr_handler = restart_coroutine;
     }
 
-    DPRINTF("s->sock=%d rd_handler=%p wr_handler=%p", s->sock,
-            rd_handler, wr_handler);
+    trace_ssh_co_yield(s->sock, rd_handler, wr_handler);
 
     aio_set_fd_handler(bdrv_get_aio_context(bs), s->sock,
                        false, rd_handler, wr_handler, NULL, &restart);
     qemu_coroutine_yield();
-    DPRINTF("s->sock=%d - back", s->sock);
+    trace_ssh_co_yield_back(s->sock);
 }
 
 /* SFTP has a function `libssh2_sftp_seek64' which seeks to a position
@@ -1003,7 +991,7 @@ static void ssh_seek(BDRVSSHState *s, int64_t offset, int flags)
     bool force = (flags & SSH_SEEK_FORCE) != 0;
 
     if (force || op_read != s->offset_op_read || offset != s->offset) {
-        DPRINTF("seeking to offset=%" PRIi64, offset);
+        trace_ssh_seek(offset);
         libssh2_sftp_seek64(s->sftp_handle, offset);
         s->offset = offset;
         s->offset_op_read = op_read;
@@ -1019,7 +1007,7 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
     char *buf, *end_of_vec;
     struct iovec *i;
 
-    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
+    trace_ssh_read(offset, size);
 
     ssh_seek(s, offset, SSH_SEEK_READ);
 
@@ -1038,9 +1026,9 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
      */
     for (got = 0; got < size; ) {
     again:
-        DPRINTF("sftp_read buf=%p size=%zu", buf, end_of_vec - buf);
+        trace_ssh_read_buf(buf, end_of_vec - buf);
         r = libssh2_sftp_read(s->sftp_handle, buf, end_of_vec - buf);
-        DPRINTF("sftp_read returned %zd", r);
+        trace_ssh_read_return(r);
 
         if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
             co_yield(s, bs);
@@ -1094,7 +1082,7 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
     char *buf, *end_of_vec;
     struct iovec *i;
 
-    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
+    trace_ssh_write(offset, size);
 
     ssh_seek(s, offset, SSH_SEEK_WRITE);
 
@@ -1108,9 +1096,9 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
 
     for (written = 0; written < size; ) {
     again:
-        DPRINTF("sftp_write buf=%p size=%zu", buf, end_of_vec - buf);
+        trace_ssh_write_buf(buf, end_of_vec - buf);
         r = libssh2_sftp_write(s->sftp_handle, buf, end_of_vec - buf);
-        DPRINTF("sftp_write returned %zd", r);
+        trace_ssh_write_return(r);
 
         if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
             co_yield(s, bs);
@@ -1187,7 +1175,7 @@ static coroutine_fn int ssh_flush(BDRVSSHState *s, BlockDriverState *bs)
 {
     int r;
 
-    DPRINTF("fsync");
+    trace_ssh_flush();
  again:
     r = libssh2_sftp_fsync(s->sftp_handle);
     if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
@@ -1238,7 +1226,7 @@ static int64_t ssh_getlength(BlockDriverState *bs)
 
     /* Note we cannot make a libssh2 call here. */
     length = (int64_t) s->attrs.filesize;
-    DPRINTF("length=%" PRIi64, length);
+    trace_ssh_getlength(length);
 
     return length;
 }
diff --git a/block/trace-events b/block/trace-events
index 3e8c47bb24..b13b1e9706 100644
--- a/block/trace-events
+++ b/block/trace-events
@@ -156,3 +156,20 @@ nvme_cmd_map_qiov_iov(void *s, int i, void *page, int pages) "s %p iov[%d] %p pa
 
 # block/iscsi.c
 iscsi_xcopy(void *src_lun, uint64_t src_off, void *dst_lun, uint64_t dst_off, uint64_t bytes, int ret) "src_lun %p offset %"PRIu64" dst_lun %p offset %"PRIu64" bytes %"PRIu64" ret %d"
+
+# block/ssh.c
+ssh_restart_coroutine(void *co) "co=%p"
+ssh_flush(void) "fsync"
+ssh_check_host_key_knownhosts(const char *key) "host key OK: %s"
+ssh_connect_to_ssh(char *path, int flags, int mode) "opening file %s flags=0x%x creat_mode=0%o"
+ssh_co_yield(int sock, void *rd_handler, void *wr_handler) "s->sock=%d rd_handler=%p wr_handler=%p"
+ssh_co_yield_back(int sock) "s->sock=%d - back"
+ssh_getlength(int64_t length) "length=%" PRIi64
+ssh_co_create_opts(uint64_t size) "total_size=%" PRIu64
+ssh_read(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
+ssh_read_buf(void *buf, size_t size) "sftp_read buf=%p size=%zu"
+ssh_read_return(size_t ret) "sftp_read returned %zd"
+ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
+ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
+ssh_write_return(size_t ret) "sftp_write returned %zd"
+ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64
-- 
2.19.2

[Qemu-devel] [PATCH 2/4] block/curl: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
---
 block/curl.c       | 29 ++++++++---------------------
 block/trace-events |  9 +++++++++
 2 files changed, 17 insertions(+), 21 deletions(-)

diff --git a/block/curl.c b/block/curl.c
index db5d2bd8ef..b7ac265d3a 100644
--- a/block/curl.c
+++ b/block/curl.c
@@ -32,22 +32,10 @@
 #include "crypto/secret.h"
 #include <curl/curl.h>
 #include "qemu/cutils.h"
+#include "trace.h"
 
-// #define DEBUG_CURL
 // #define DEBUG_VERBOSE
 
-#ifdef DEBUG_CURL
-#define DEBUG_CURL_PRINT 1
-#else
-#define DEBUG_CURL_PRINT 0
-#endif
-#define DPRINTF(fmt, ...)                                            \
-    do {                                                             \
-        if (DEBUG_CURL_PRINT) {                                      \
-            fprintf(stderr, fmt, ## __VA_ARGS__);                    \
-        }                                                            \
-    } while (0)
-
 #if LIBCURL_VERSION_NUM >= 0x071000
 /* The multi interface timer callback was introduced in 7.16.0 */
 #define NEED_CURL_TIMER_CALLBACK
@@ -154,7 +142,7 @@ static int curl_timer_cb(CURLM *multi, long timeout_ms, void *opaque)
 {
     BDRVCURLState *s = opaque;
 
-    DPRINTF("CURL: timer callback timeout_ms %ld\n", timeout_ms);
+    trace_curl_timer_cb(timeout_ms);
     if (timeout_ms == -1) {
         timer_del(&s->timer);
     } else {
@@ -193,7 +181,7 @@ static int curl_sock_cb(CURL *curl, curl_socket_t fd, int action,
     }
     socket = NULL;
 
-    DPRINTF("CURL (AIO): Sock action %d on fd %d\n", action, (int)fd);
+    trace_curl_sock_cb(action, (int)fd);
     switch (action) {
         case CURL_POLL_IN:
             aio_set_fd_handler(s->aio_context, fd, false,
@@ -238,7 +226,7 @@ static size_t curl_read_cb(void *ptr, size_t size, size_t nmemb, void *opaque)
     size_t realsize = size * nmemb;
     int i;
 
-    DPRINTF("CURL: Just reading %zd bytes\n", realsize);
+    trace_curl_read_cb(realsize);
 
     if (!s || !s->orig_buf) {
         goto read_end;
@@ -777,7 +765,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
         }
     }
 
-    DPRINTF("CURL: Opening %s\n", file);
+    trace_curl_open(file);
     qemu_co_queue_init(&s->free_state_waitq);
     s->aio_context = bdrv_get_aio_context(bs);
     s->url = g_strdup(file);
@@ -830,7 +818,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
                 "Server does not support 'range' (byte ranges).");
         goto out;
     }
-    DPRINTF("CURL: Size = %" PRIu64 "\n", s->len);
+    trace_curl_open_size(s->len);
 
     qemu_mutex_lock(&s->mutex);
     curl_clean_state(state);
@@ -908,8 +896,7 @@ static void curl_setup_preadv(BlockDriverState *bs, CURLAIOCB *acb)
     state->acb[0] = acb;
 
     snprintf(state->range, 127, "%" PRIu64 "-%" PRIu64, start, end);
-    DPRINTF("CURL (AIO): Reading %" PRIu64 " at %" PRIu64 " (%s)\n",
-            acb->bytes, start, state->range);
+    trace_curl_setup_preadv(acb->bytes, start, state->range);
     curl_easy_setopt(state->curl, CURLOPT_RANGE, state->range);
 
     curl_multi_add_handle(s->multi, state->curl);
@@ -943,7 +930,7 @@ static void curl_close(BlockDriverState *bs)
 {
     BDRVCURLState *s = bs->opaque;
 
-    DPRINTF("CURL: Close\n");
+    trace_curl_close();
     curl_detach_aio_context(bs);
     qemu_mutex_destroy(&s->mutex);
 
diff --git a/block/trace-events b/block/trace-events
index b13b1e9706..5b83280b02 100644
--- a/block/trace-events
+++ b/block/trace-events
@@ -173,3 +173,12 @@ ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
 ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
 ssh_write_return(size_t ret) "sftp_write returned %zd"
 ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64
+
+# block/curl.c
+curl_timer_cb(long timeout_ms) "timer callback timeout_ms %ld"
+curl_sock_cb(int action, int fd) "sock action %d on fd %d"
+curl_read_cb(size_t realsize) "just reading %zd bytes"
+curl_open(const char *file) "opening %s"
+curl_open_size(uint64_t size) "size = %" PRIu64
+curl_setup_preadv(uint64_t bytes, uint64_t start, const char *range) "reading %" PRIu64 " at %" PRIu64 " (%s)"
+curl_close(void) "close"
-- 
2.19.2

[Qemu-devel] [PATCH 3/4] block/file-posix: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
---
 block/file-posix.c | 25 ++++++-------------------
 block/trace-events |  7 +++++++
 2 files changed, 13 insertions(+), 19 deletions(-)

diff --git a/block/file-posix.c b/block/file-posix.c
index 07bbdab953..cf90899a6e 100644
--- a/block/file-posix.c
+++ b/block/file-posix.c
@@ -102,19 +102,7 @@
 #include <xfs/xfs.h>
 #endif
 
-//#define DEBUG_BLOCK
-
-#ifdef DEBUG_BLOCK
-# define DEBUG_BLOCK_PRINT 1
-#else
-# define DEBUG_BLOCK_PRINT 0
-#endif
-#define DPRINTF(fmt, ...) \
-do { \
-    if (DEBUG_BLOCK_PRINT) { \
-        printf(fmt, ## __VA_ARGS__); \
-    } \
-} while (0)
+#include "trace.h"
 
 /* OS X does not have O_DSYNC */
 #ifndef O_DSYNC
@@ -1386,7 +1374,7 @@ static int xfs_write_zeroes(BDRVRawState *s, int64_t offset, uint64_t bytes)
 
     if (xfsctl(NULL, s->fd, XFS_IOC_ZERO_RANGE, &fl) < 0) {
         err = errno;
-        DPRINTF("cannot write zero range (%s)\n", strerror(errno));
+        trace_file_xfs_write_zeroes(strerror(errno));
         return -err;
     }
 
@@ -1405,7 +1393,7 @@ static int xfs_discard(BDRVRawState *s, int64_t offset, uint64_t bytes)
 
     if (xfsctl(NULL, s->fd, XFS_IOC_UNRESVSP64, &fl) < 0) {
         err = errno;
-        DPRINTF("cannot punch hole (%s)\n", strerror(errno));
+        trace_file_xfs_discard(strerror(errno));
         return -err;
     }
 
@@ -2798,7 +2786,7 @@ static char *FindEjectableOpticalMedia(io_iterator_t *mediaIterator)
 
         /* If a match was found, leave the loop */
         if (*mediaIterator != 0) {
-            DPRINTF("Matching using %s\n", matching_array[index]);
+            trace_file_FindEjectableOpticalMedia(matching_array[index]);
             mediaType = g_strdup(matching_array[index]);
             break;
         }
@@ -2858,7 +2846,7 @@ static bool setup_cdrom(char *bsd_path, Error **errp)
     if (partition_found == false) {
         error_setg(errp, "Failed to find a working partition on disc");
     } else {
-        DPRINTF("Using %s as optical disc\n", test_partition);
+        trace_file_setup_cdrom(test_partition);
         pstrcpy(bsd_path, MAXPATHLEN, test_partition);
     }
     return partition_found;
@@ -2953,8 +2941,7 @@ static bool hdev_is_sg(BlockDriverState *bs)
 
     ret = ioctl(s->fd, SG_GET_SCSI_ID, &scsiid);
     if (ret >= 0) {
-        DPRINTF("SG device found: type=%d, version=%d\n",
-            scsiid.scsi_type, sg_version);
+        trace_file_hdev_is_sg(scsiid.scsi_type, sg_version);
         return true;
     }
 
diff --git a/block/trace-events b/block/trace-events
index 5b83280b02..49f31966e7 100644
--- a/block/trace-events
+++ b/block/trace-events
@@ -182,3 +182,10 @@ curl_open(const char *file) "opening %s"
 curl_open_size(uint64_t size) "size = %" PRIu64
 curl_setup_preadv(uint64_t bytes, uint64_t start, const char *range) "reading %" PRIu64 " at %" PRIu64 " (%s)"
 curl_close(void) "close"
+
+# block/file-posix.c
+file_xfs_write_zeroes(const char *error) "cannot write zero range (%s)"
+file_xfs_discard(const char* error) "cannot punch hole (%s)"
+file_FindEjectableOpticalMedia(const char *media) "Matching using %s"
+file_setup_cdrom(const char *partition) "Using %s as optical disc"
+file_hdev_is_sg(int type, int version) "SG device found: type=%d, version=%d"
-- 
2.19.2

[Qemu-devel] [PATCH 4/4] block/sheepdog: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
---
 block/sheepdog.c   | 47 +++++++++++++++++-----------------------------
 block/trace-events | 14 ++++++++++++++
 2 files changed, 31 insertions(+), 30 deletions(-)

diff --git a/block/sheepdog.c b/block/sheepdog.c
index 0125df9d49..a5000d271b 100644
--- a/block/sheepdog.c
+++ b/block/sheepdog.c
@@ -28,6 +28,7 @@
 #include "sysemu/block-backend.h"
 #include "qemu/bitops.h"
 #include "qemu/cutils.h"
+#include "trace.h"
 
 #define SD_PROTO_VER 0x01
 
@@ -299,19 +300,6 @@ static inline size_t count_data_objs(const struct SheepdogInode *inode)
                         (1UL << inode->block_size_shift));
 }
 
-#undef DPRINTF
-#ifdef DEBUG_SDOG
-#define DEBUG_SDOG_PRINT 1
-#else
-#define DEBUG_SDOG_PRINT 0
-#endif
-#define DPRINTF(fmt, args...)                                           \
-    do {                                                                \
-        if (DEBUG_SDOG_PRINT) {                                         \
-            fprintf(stderr, "%s %d: " fmt, __func__, __LINE__, ##args); \
-        }                                                               \
-    } while (0)
-
 typedef struct SheepdogAIOCB SheepdogAIOCB;
 typedef struct BDRVSheepdogState BDRVSheepdogState;
 
@@ -750,7 +738,7 @@ static coroutine_fn void reconnect_to_sdog(void *opaque)
         Error *local_err = NULL;
         s->fd = get_sheep_fd(s, &local_err);
         if (s->fd < 0) {
-            DPRINTF("Wait for connection to be established\n");
+            trace_sd_reconnect_to_sdog();
             error_report_err(local_err);
             qemu_co_sleep_ns(QEMU_CLOCK_REALTIME, 1000000000ULL);
         }
@@ -847,7 +835,7 @@ static void coroutine_fn aio_read_response(void *opaque)
         break;
     case AIOCB_FLUSH_CACHE:
         if (rsp.result == SD_RES_INVALID_PARMS) {
-            DPRINTF("disable cache since the server doesn't support it\n");
+            trace_sd_aio_read_response();
             s->cache_flags = SD_FLAG_CMD_DIRECT;
             rsp.result = SD_RES_SUCCESS;
         }
@@ -1639,7 +1627,7 @@ static int sd_open(BlockDriverState *bs, QDict *options, int flags,
     s->discard_supported = true;
 
     if (snap_id || tag[0]) {
-        DPRINTF("%" PRIx32 " snapshot inode was open.\n", vid);
+        trace_sd_open(vid);
         s->is_snapshot = true;
     }
 
@@ -2252,7 +2240,7 @@ static void sd_close(BlockDriverState *bs)
     unsigned int wlen, rlen = 0;
     int fd, ret;
 
-    DPRINTF("%s\n", s->name);
+    trace_sd_close(s->name);
 
     fd = connect_to_sdog(s, &local_err);
     if (fd < 0) {
@@ -2429,7 +2417,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
     char *buf;
     bool deleted;
 
-    DPRINTF("%" PRIx32 " is snapshot.\n", s->inode.vdi_id);
+    trace_sd_create_branch_snapshot(s->inode.vdi_id);
 
     buf = g_malloc(SD_INODE_SIZE);
 
@@ -2445,7 +2433,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
         goto out;
     }
 
-    DPRINTF("%" PRIx32 " is created.\n", vid);
+    trace_sd_create_branch_created(vid);
 
     fd = connect_to_sdog(s, &local_err);
     if (fd < 0) {
@@ -2467,7 +2455,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
 
     s->is_snapshot = false;
     ret = 0;
-    DPRINTF("%" PRIx32 " was newly created.\n", s->inode.vdi_id);
+    trace_sd_create_branch_new(s->inode.vdi_id);
 
 out:
     g_free(buf);
@@ -2561,11 +2549,11 @@ static void coroutine_fn sd_co_rw_vector(SheepdogAIOCB *acb)
         }
 
         if (create) {
-            DPRINTF("update ino (%" PRIu32 ") %" PRIu64 " %" PRIu64 " %ld\n",
-                    inode->vdi_id, oid,
-                    vid_to_data_oid(inode->data_vdi_id[idx], idx), idx);
+            trace_sd_co_rw_vector_update(inode->vdi_id, oid,
+                                  vid_to_data_oid(inode->data_vdi_id[idx], idx),
+                                  idx);
             oid = vid_to_data_oid(inode->vdi_id, idx);
-            DPRINTF("new oid %" PRIx64 "\n", oid);
+            trace_sd_co_rw_vector_new(oid);
         }
 
         aio_req = alloc_aio_req(s, acb, oid, len, offset, flags, create,
@@ -2670,9 +2658,8 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
     SheepdogInode *inode;
     unsigned int datalen;
 
-    DPRINTF("sn_info: name %s id_str %s s: name %s vm_state_size %" PRId64 " "
-            "is_snapshot %d\n", sn_info->name, sn_info->id_str,
-            s->name, sn_info->vm_state_size, s->is_snapshot);
+    trace_sd_snapshot_create_info(sn_info->name, sn_info->id_str, s->name,
+                                  sn_info->vm_state_size, s->is_snapshot);
 
     if (s->is_snapshot) {
         error_report("You can't create a snapshot of a snapshot VDI, "
@@ -2681,7 +2668,7 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
         return -EINVAL;
     }
 
-    DPRINTF("%s %s\n", sn_info->name, sn_info->id_str);
+    trace_sd_snapshot_create(sn_info->name, sn_info->id_str);
 
     s->inode.vm_state_size = sn_info->vm_state_size;
     s->inode.vm_clock_nsec = sn_info->vm_clock_nsec;
@@ -2726,8 +2713,8 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
     }
 
     memcpy(&s->inode, inode, datalen);
-    DPRINTF("s->inode: name %s snap_id %x oid %x\n",
-            s->inode.name, s->inode.snap_id, s->inode.vdi_id);
+    trace_sd_snapshot_create_inode(s->inode.name, s->inode.snap_id,
+                                   s->inode.vdi_id);
 
 cleanup:
     g_free(inode);
diff --git a/block/trace-events b/block/trace-events
index 49f31966e7..7a92d7b3db 100644
--- a/block/trace-events
+++ b/block/trace-events
@@ -189,3 +189,17 @@ file_xfs_discard(const char* error) "cannot punch hole (%s)"
 file_FindEjectableOpticalMedia(const char *media) "Matching using %s"
 file_setup_cdrom(const char *partition) "Using %s as optical disc"
 file_hdev_is_sg(int type, int version) "SG device found: type=%d, version=%d"
+
+# block/sheepdog.c
+sd_reconnect_to_sdog(void) "Wait for connection to be established"
+sd_aio_read_response(void) "disable cache since the server doesn't support it"
+sd_open(uint32_t vid) "0x%" PRIx32 " snapshot inode was open."
+sd_close(const char *name) "%s"
+sd_create_branch_snapshot(uint32_t vdi) "0x%" PRIx32 " is snapshot."
+sd_create_branch_created(uint32_t vdi) "0x%" PRIx32 " is created."
+sd_create_branch_new(uint32_t vdi) "0x%" PRIx32 " was newly created."
+sd_co_rw_vector_update(uint32_t vdi, uint64_t oid, uint64_t data, long idx) "update ino (%" PRIu32 ") %" PRIu64 " %" PRIu64 " %ld"
+sd_co_rw_vector_new(uint64_t oid) "new oid 0x%" PRIx64
+sd_snapshot_create_info(const char *sn_name, const char *id, const char *name, int64_t size, int is_snapshot) "sn_info: name %s id_str %s s: name %s vm_state_size %" PRId64 " " "is_snapshot %d"
+sd_snapshot_create(const char *sn_name, const char *id) "%s %s"
+sd_snapshot_create_inode(const char *name, uint32_t snap, uint32_t vdi) "s->inode: name %s snap_id 0x%x vdi 0x%x"
-- 
2.19.2

Re: [Qemu-devel] [PATCH 1/4] block/ssh: Convert from DPRINTF() macro to trace events

[Richard W.M. Jones]

On Wed, Dec 12, 2018 at 08:40:06PM +0100, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  block/ssh.c        | 46 +++++++++++++++++-----------------------------
>  block/trace-events | 17 +++++++++++++++++
>  2 files changed, 34 insertions(+), 29 deletions(-)
> 
> diff --git a/block/ssh.c b/block/ssh.c
> index 7fbc27abdf..bbc513e095 100644
> --- a/block/ssh.c
> +++ b/block/ssh.c
> @@ -41,27 +41,17 @@
>  #include "qapi/qmp/qstring.h"
>  #include "qapi/qobject-input-visitor.h"
>  #include "qapi/qobject-output-visitor.h"
> +#include "trace.h"
>  
> -/* DEBUG_SSH=1 enables the DPRINTF (debugging printf) statements in
> - * this block driver code.
> - *
> +/*
>   * TRACE_LIBSSH2=<bitmask> enables tracing in libssh2 itself.  Note
>   * that this requires that libssh2 was specially compiled with the
>   * `./configure --enable-debug' option, so most likely you will have
>   * to compile it yourself.  The meaning of <bitmask> is described
>   * here: http://www.libssh2.org/libssh2_trace.html
>   */
> -#define DEBUG_SSH     0
>  #define TRACE_LIBSSH2 0 /* or try: LIBSSH2_TRACE_SFTP */
>  
> -#define DPRINTF(fmt, ...)                           \
> -    do {                                            \
> -        if (DEBUG_SSH) {                            \
> -            fprintf(stderr, "ssh: %-15s " fmt "\n", \
> -                    __func__, ##__VA_ARGS__);       \
> -        }                                           \
> -    } while (0)
> -
>  typedef struct BDRVSSHState {
>      /* Coroutine. */
>      CoMutex lock;
> @@ -336,7 +326,7 @@ static int check_host_key_knownhosts(BDRVSSHState *s,
>      switch (r) {
>      case LIBSSH2_KNOWNHOST_CHECK_MATCH:
>          /* OK */
> -        DPRINTF("host key OK: %s", found->key);
> +        trace_ssh_check_host_key_knownhosts(found->key);
>          break;
>      case LIBSSH2_KNOWNHOST_CHECK_MISMATCH:
>          ret = -EINVAL;
> @@ -721,8 +711,7 @@ static int connect_to_ssh(BDRVSSHState *s, BlockdevOptionsSsh *opts,
>      }
>  
>      /* Open the remote file. */
> -    DPRINTF("opening file %s flags=0x%x creat_mode=0%o",
> -            opts->path, ssh_flags, creat_mode);
> +    trace_ssh_connect_to_ssh(opts->path, ssh_flags, creat_mode);
>      s->sftp_handle = libssh2_sftp_open(s->sftp, opts->path, ssh_flags,
>                                         creat_mode);
>      if (!s->sftp_handle) {
> @@ -890,7 +879,7 @@ static int coroutine_fn ssh_co_create_opts(const char *filename, QemuOpts *opts,
>      /* Get desired file size. */
>      ssh_opts->size = ROUND_UP(qemu_opt_get_size_del(opts, BLOCK_OPT_SIZE, 0),
>                                BDRV_SECTOR_SIZE);
> -    DPRINTF("total_size=%" PRIi64, ssh_opts->size);
> +    trace_ssh_co_create_opts(ssh_opts->size);
>  
>      uri_options = qdict_new();
>      ret = parse_uri(filename, uri_options, errp);
> @@ -946,7 +935,7 @@ static void restart_coroutine(void *opaque)
>      BDRVSSHState *s = bs->opaque;
>      AioContext *ctx = bdrv_get_aio_context(bs);
>  
> -    DPRINTF("co=%p", restart->co);
> +    trace_ssh_restart_coroutine(restart->co);
>      aio_set_fd_handler(ctx, s->sock, false, NULL, NULL, NULL, NULL);
>  
>      aio_co_wake(restart->co);
> @@ -974,13 +963,12 @@ static coroutine_fn void co_yield(BDRVSSHState *s, BlockDriverState *bs)
>          wr_handler = restart_coroutine;
>      }
>  
> -    DPRINTF("s->sock=%d rd_handler=%p wr_handler=%p", s->sock,
> -            rd_handler, wr_handler);
> +    trace_ssh_co_yield(s->sock, rd_handler, wr_handler);
>  
>      aio_set_fd_handler(bdrv_get_aio_context(bs), s->sock,
>                         false, rd_handler, wr_handler, NULL, &restart);
>      qemu_coroutine_yield();
> -    DPRINTF("s->sock=%d - back", s->sock);
> +    trace_ssh_co_yield_back(s->sock);
>  }
>  
>  /* SFTP has a function `libssh2_sftp_seek64' which seeks to a position
> @@ -1003,7 +991,7 @@ static void ssh_seek(BDRVSSHState *s, int64_t offset, int flags)
>      bool force = (flags & SSH_SEEK_FORCE) != 0;
>  
>      if (force || op_read != s->offset_op_read || offset != s->offset) {
> -        DPRINTF("seeking to offset=%" PRIi64, offset);
> +        trace_ssh_seek(offset);
>          libssh2_sftp_seek64(s->sftp_handle, offset);
>          s->offset = offset;
>          s->offset_op_read = op_read;
> @@ -1019,7 +1007,7 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
>      char *buf, *end_of_vec;
>      struct iovec *i;
>  
> -    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
> +    trace_ssh_read(offset, size);
>  
>      ssh_seek(s, offset, SSH_SEEK_READ);
>  
> @@ -1038,9 +1026,9 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
>       */
>      for (got = 0; got < size; ) {
>      again:
> -        DPRINTF("sftp_read buf=%p size=%zu", buf, end_of_vec - buf);
> +        trace_ssh_read_buf(buf, end_of_vec - buf);
>          r = libssh2_sftp_read(s->sftp_handle, buf, end_of_vec - buf);
> -        DPRINTF("sftp_read returned %zd", r);
> +        trace_ssh_read_return(r);
>  
>          if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
>              co_yield(s, bs);
> @@ -1094,7 +1082,7 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
>      char *buf, *end_of_vec;
>      struct iovec *i;
>  
> -    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
> +    trace_ssh_write(offset, size);
>  
>      ssh_seek(s, offset, SSH_SEEK_WRITE);
>  
> @@ -1108,9 +1096,9 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
>  
>      for (written = 0; written < size; ) {
>      again:
> -        DPRINTF("sftp_write buf=%p size=%zu", buf, end_of_vec - buf);
> +        trace_ssh_write_buf(buf, end_of_vec - buf);
>          r = libssh2_sftp_write(s->sftp_handle, buf, end_of_vec - buf);
> -        DPRINTF("sftp_write returned %zd", r);
> +        trace_ssh_write_return(r);
>  
>          if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
>              co_yield(s, bs);
> @@ -1187,7 +1175,7 @@ static coroutine_fn int ssh_flush(BDRVSSHState *s, BlockDriverState *bs)
>  {
>      int r;
>  
> -    DPRINTF("fsync");
> +    trace_ssh_flush();
>   again:
>      r = libssh2_sftp_fsync(s->sftp_handle);
>      if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
> @@ -1238,7 +1226,7 @@ static int64_t ssh_getlength(BlockDriverState *bs)
>  
>      /* Note we cannot make a libssh2 call here. */
>      length = (int64_t) s->attrs.filesize;
> -    DPRINTF("length=%" PRIi64, length);
> +    trace_ssh_getlength(length);
>  
>      return length;
>  }
> diff --git a/block/trace-events b/block/trace-events
> index 3e8c47bb24..b13b1e9706 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -156,3 +156,20 @@ nvme_cmd_map_qiov_iov(void *s, int i, void *page, int pages) "s %p iov[%d] %p pa
>  
>  # block/iscsi.c
>  iscsi_xcopy(void *src_lun, uint64_t src_off, void *dst_lun, uint64_t dst_off, uint64_t bytes, int ret) "src_lun %p offset %"PRIu64" dst_lun %p offset %"PRIu64" bytes %"PRIu64" ret %d"
> +
> +# block/ssh.c
> +ssh_restart_coroutine(void *co) "co=%p"
> +ssh_flush(void) "fsync"
> +ssh_check_host_key_knownhosts(const char *key) "host key OK: %s"
> +ssh_connect_to_ssh(char *path, int flags, int mode) "opening file %s flags=0x%x creat_mode=0%o"
> +ssh_co_yield(int sock, void *rd_handler, void *wr_handler) "s->sock=%d rd_handler=%p wr_handler=%p"
> +ssh_co_yield_back(int sock) "s->sock=%d - back"
> +ssh_getlength(int64_t length) "length=%" PRIi64
> +ssh_co_create_opts(uint64_t size) "total_size=%" PRIu64
> +ssh_read(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
> +ssh_read_buf(void *buf, size_t size) "sftp_read buf=%p size=%zu"
> +ssh_read_return(size_t ret) "sftp_read returned %zd"
> +ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
> +ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
> +ssh_write_return(size_t ret) "sftp_write returned %zd"
> +ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64

Looks reasonable to me, so:

Reviewed-by: Richard W.M. Jones <rjones@redhat.com>

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-p2v converts physical machines to virtual machines.  Boot with a
live CD or over the network (PXE) and turn machines into KVM guests.
http://libguestfs.org/virt-v2v

Re: [Qemu-devel] [PATCH 2/4] block/curl: Convert from DPRINTF() macro to trace events

[Richard W.M. Jones]

On Wed, Dec 12, 2018 at 08:40:07PM +0100, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  block/curl.c       | 29 ++++++++---------------------
>  block/trace-events |  9 +++++++++
>  2 files changed, 17 insertions(+), 21 deletions(-)
> 
> diff --git a/block/curl.c b/block/curl.c
> index db5d2bd8ef..b7ac265d3a 100644
> --- a/block/curl.c
> +++ b/block/curl.c
> @@ -32,22 +32,10 @@
>  #include "crypto/secret.h"
>  #include <curl/curl.h>
>  #include "qemu/cutils.h"
> +#include "trace.h"
>  
> -// #define DEBUG_CURL
>  // #define DEBUG_VERBOSE
>  
> -#ifdef DEBUG_CURL
> -#define DEBUG_CURL_PRINT 1
> -#else
> -#define DEBUG_CURL_PRINT 0
> -#endif
> -#define DPRINTF(fmt, ...)                                            \
> -    do {                                                             \
> -        if (DEBUG_CURL_PRINT) {                                      \
> -            fprintf(stderr, fmt, ## __VA_ARGS__);                    \
> -        }                                                            \
> -    } while (0)
> -
>  #if LIBCURL_VERSION_NUM >= 0x071000
>  /* The multi interface timer callback was introduced in 7.16.0 */
>  #define NEED_CURL_TIMER_CALLBACK
> @@ -154,7 +142,7 @@ static int curl_timer_cb(CURLM *multi, long timeout_ms, void *opaque)
>  {
>      BDRVCURLState *s = opaque;
>  
> -    DPRINTF("CURL: timer callback timeout_ms %ld\n", timeout_ms);
> +    trace_curl_timer_cb(timeout_ms);
>      if (timeout_ms == -1) {
>          timer_del(&s->timer);
>      } else {
> @@ -193,7 +181,7 @@ static int curl_sock_cb(CURL *curl, curl_socket_t fd, int action,
>      }
>      socket = NULL;
>  
> -    DPRINTF("CURL (AIO): Sock action %d on fd %d\n", action, (int)fd);
> +    trace_curl_sock_cb(action, (int)fd);
>      switch (action) {
>          case CURL_POLL_IN:
>              aio_set_fd_handler(s->aio_context, fd, false,
> @@ -238,7 +226,7 @@ static size_t curl_read_cb(void *ptr, size_t size, size_t nmemb, void *opaque)
>      size_t realsize = size * nmemb;
>      int i;
>  
> -    DPRINTF("CURL: Just reading %zd bytes\n", realsize);
> +    trace_curl_read_cb(realsize);
>  
>      if (!s || !s->orig_buf) {
>          goto read_end;
> @@ -777,7 +765,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
>          }
>      }
>  
> -    DPRINTF("CURL: Opening %s\n", file);
> +    trace_curl_open(file);
>      qemu_co_queue_init(&s->free_state_waitq);
>      s->aio_context = bdrv_get_aio_context(bs);
>      s->url = g_strdup(file);
> @@ -830,7 +818,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
>                  "Server does not support 'range' (byte ranges).");
>          goto out;
>      }
> -    DPRINTF("CURL: Size = %" PRIu64 "\n", s->len);
> +    trace_curl_open_size(s->len);
>  
>      qemu_mutex_lock(&s->mutex);
>      curl_clean_state(state);
> @@ -908,8 +896,7 @@ static void curl_setup_preadv(BlockDriverState *bs, CURLAIOCB *acb)
>      state->acb[0] = acb;
>  
>      snprintf(state->range, 127, "%" PRIu64 "-%" PRIu64, start, end);
> -    DPRINTF("CURL (AIO): Reading %" PRIu64 " at %" PRIu64 " (%s)\n",
> -            acb->bytes, start, state->range);
> +    trace_curl_setup_preadv(acb->bytes, start, state->range);
>      curl_easy_setopt(state->curl, CURLOPT_RANGE, state->range);
>  
>      curl_multi_add_handle(s->multi, state->curl);
> @@ -943,7 +930,7 @@ static void curl_close(BlockDriverState *bs)
>  {
>      BDRVCURLState *s = bs->opaque;
>  
> -    DPRINTF("CURL: Close\n");
> +    trace_curl_close();
>      curl_detach_aio_context(bs);
>      qemu_mutex_destroy(&s->mutex);
>  
> diff --git a/block/trace-events b/block/trace-events
> index b13b1e9706..5b83280b02 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -173,3 +173,12 @@ ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
>  ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
>  ssh_write_return(size_t ret) "sftp_write returned %zd"
>  ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64
> +
> +# block/curl.c
> +curl_timer_cb(long timeout_ms) "timer callback timeout_ms %ld"
> +curl_sock_cb(int action, int fd) "sock action %d on fd %d"
> +curl_read_cb(size_t realsize) "just reading %zd bytes"
> +curl_open(const char *file) "opening %s"
> +curl_open_size(uint64_t size) "size = %" PRIu64
> +curl_setup_preadv(uint64_t bytes, uint64_t start, const char *range) "reading %" PRIu64 " at %" PRIu64 " (%s)"
> +curl_close(void) "close"


Reviewed-by: Richard W.M. Jones <rjones@redhat.com>

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-top is 'top' for virtual machines.  Tiny program with many
powerful monitoring features, net stats, disk stats, logging, etc.
http://people.redhat.com/~rjones/virt-top

Re: [Qemu-devel] [PATCH 1/4] block/ssh: Convert from DPRINTF() macro to trace events

[Philippe Mathieu-Daudé]

On 12/12/18 8:40 PM, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  block/ssh.c        | 46 +++++++++++++++++-----------------------------
>  block/trace-events | 17 +++++++++++++++++
>  2 files changed, 34 insertions(+), 29 deletions(-)
> 
> diff --git a/block/ssh.c b/block/ssh.c
> index 7fbc27abdf..bbc513e095 100644
> --- a/block/ssh.c
> +++ b/block/ssh.c
> @@ -41,27 +41,17 @@
>  #include "qapi/qmp/qstring.h"
>  #include "qapi/qobject-input-visitor.h"
>  #include "qapi/qobject-output-visitor.h"
> +#include "trace.h"
>  
> -/* DEBUG_SSH=1 enables the DPRINTF (debugging printf) statements in
> - * this block driver code.
> - *
> +/*
>   * TRACE_LIBSSH2=<bitmask> enables tracing in libssh2 itself.  Note
>   * that this requires that libssh2 was specially compiled with the
>   * `./configure --enable-debug' option, so most likely you will have
>   * to compile it yourself.  The meaning of <bitmask> is described
>   * here: http://www.libssh2.org/libssh2_trace.html
>   */
> -#define DEBUG_SSH     0
>  #define TRACE_LIBSSH2 0 /* or try: LIBSSH2_TRACE_SFTP */
>  
> -#define DPRINTF(fmt, ...)                           \
> -    do {                                            \
> -        if (DEBUG_SSH) {                            \
> -            fprintf(stderr, "ssh: %-15s " fmt "\n", \
> -                    __func__, ##__VA_ARGS__);       \
> -        }                                           \
> -    } while (0)
> -
>  typedef struct BDRVSSHState {
>      /* Coroutine. */
>      CoMutex lock;
> @@ -336,7 +326,7 @@ static int check_host_key_knownhosts(BDRVSSHState *s,
>      switch (r) {
>      case LIBSSH2_KNOWNHOST_CHECK_MATCH:
>          /* OK */
> -        DPRINTF("host key OK: %s", found->key);
> +        trace_ssh_check_host_key_knownhosts(found->key);
>          break;
>      case LIBSSH2_KNOWNHOST_CHECK_MISMATCH:
>          ret = -EINVAL;
> @@ -721,8 +711,7 @@ static int connect_to_ssh(BDRVSSHState *s, BlockdevOptionsSsh *opts,
>      }
>  
>      /* Open the remote file. */
> -    DPRINTF("opening file %s flags=0x%x creat_mode=0%o",
> -            opts->path, ssh_flags, creat_mode);
> +    trace_ssh_connect_to_ssh(opts->path, ssh_flags, creat_mode);
>      s->sftp_handle = libssh2_sftp_open(s->sftp, opts->path, ssh_flags,
>                                         creat_mode);
>      if (!s->sftp_handle) {
> @@ -890,7 +879,7 @@ static int coroutine_fn ssh_co_create_opts(const char *filename, QemuOpts *opts,
>      /* Get desired file size. */
>      ssh_opts->size = ROUND_UP(qemu_opt_get_size_del(opts, BLOCK_OPT_SIZE, 0),
>                                BDRV_SECTOR_SIZE);
> -    DPRINTF("total_size=%" PRIi64, ssh_opts->size);
> +    trace_ssh_co_create_opts(ssh_opts->size);
>  
>      uri_options = qdict_new();
>      ret = parse_uri(filename, uri_options, errp);
> @@ -946,7 +935,7 @@ static void restart_coroutine(void *opaque)
>      BDRVSSHState *s = bs->opaque;
>      AioContext *ctx = bdrv_get_aio_context(bs);
>  
> -    DPRINTF("co=%p", restart->co);
> +    trace_ssh_restart_coroutine(restart->co);
>      aio_set_fd_handler(ctx, s->sock, false, NULL, NULL, NULL, NULL);
>  
>      aio_co_wake(restart->co);
> @@ -974,13 +963,12 @@ static coroutine_fn void co_yield(BDRVSSHState *s, BlockDriverState *bs)
>          wr_handler = restart_coroutine;
>      }
>  
> -    DPRINTF("s->sock=%d rd_handler=%p wr_handler=%p", s->sock,
> -            rd_handler, wr_handler);
> +    trace_ssh_co_yield(s->sock, rd_handler, wr_handler);
>  
>      aio_set_fd_handler(bdrv_get_aio_context(bs), s->sock,
>                         false, rd_handler, wr_handler, NULL, &restart);
>      qemu_coroutine_yield();
> -    DPRINTF("s->sock=%d - back", s->sock);
> +    trace_ssh_co_yield_back(s->sock);
>  }
>  
>  /* SFTP has a function `libssh2_sftp_seek64' which seeks to a position
> @@ -1003,7 +991,7 @@ static void ssh_seek(BDRVSSHState *s, int64_t offset, int flags)
>      bool force = (flags & SSH_SEEK_FORCE) != 0;
>  
>      if (force || op_read != s->offset_op_read || offset != s->offset) {
> -        DPRINTF("seeking to offset=%" PRIi64, offset);
> +        trace_ssh_seek(offset);
>          libssh2_sftp_seek64(s->sftp_handle, offset);
>          s->offset = offset;
>          s->offset_op_read = op_read;
> @@ -1019,7 +1007,7 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
>      char *buf, *end_of_vec;
>      struct iovec *i;
>  
> -    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
> +    trace_ssh_read(offset, size);
>  
>      ssh_seek(s, offset, SSH_SEEK_READ);
>  
> @@ -1038,9 +1026,9 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
>       */
>      for (got = 0; got < size; ) {
>      again:
> -        DPRINTF("sftp_read buf=%p size=%zu", buf, end_of_vec - buf);
> +        trace_ssh_read_buf(buf, end_of_vec - buf);
>          r = libssh2_sftp_read(s->sftp_handle, buf, end_of_vec - buf);
> -        DPRINTF("sftp_read returned %zd", r);
> +        trace_ssh_read_return(r);
>  
>          if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
>              co_yield(s, bs);
> @@ -1094,7 +1082,7 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
>      char *buf, *end_of_vec;
>      struct iovec *i;
>  
> -    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
> +    trace_ssh_write(offset, size);
>  
>      ssh_seek(s, offset, SSH_SEEK_WRITE);
>  
> @@ -1108,9 +1096,9 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
>  
>      for (written = 0; written < size; ) {
>      again:
> -        DPRINTF("sftp_write buf=%p size=%zu", buf, end_of_vec - buf);
> +        trace_ssh_write_buf(buf, end_of_vec - buf);
>          r = libssh2_sftp_write(s->sftp_handle, buf, end_of_vec - buf);
> -        DPRINTF("sftp_write returned %zd", r);
> +        trace_ssh_write_return(r);
>  
>          if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
>              co_yield(s, bs);
> @@ -1187,7 +1175,7 @@ static coroutine_fn int ssh_flush(BDRVSSHState *s, BlockDriverState *bs)
>  {
>      int r;
>  
> -    DPRINTF("fsync");
> +    trace_ssh_flush();
>   again:
>      r = libssh2_sftp_fsync(s->sftp_handle);
>      if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
> @@ -1238,7 +1226,7 @@ static int64_t ssh_getlength(BlockDriverState *bs)
>  
>      /* Note we cannot make a libssh2 call here. */
>      length = (int64_t) s->attrs.filesize;
> -    DPRINTF("length=%" PRIi64, length);
> +    trace_ssh_getlength(length);
>  
>      return length;
>  }
> diff --git a/block/trace-events b/block/trace-events
> index 3e8c47bb24..b13b1e9706 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -156,3 +156,20 @@ nvme_cmd_map_qiov_iov(void *s, int i, void *page, int pages) "s %p iov[%d] %p pa
>  
>  # block/iscsi.c
>  iscsi_xcopy(void *src_lun, uint64_t src_off, void *dst_lun, uint64_t dst_off, uint64_t bytes, int ret) "src_lun %p offset %"PRIu64" dst_lun %p offset %"PRIu64" bytes %"PRIu64" ret %d"
> +
> +# block/ssh.c
> +ssh_restart_coroutine(void *co) "co=%p"
> +ssh_flush(void) "fsync"
> +ssh_check_host_key_knownhosts(const char *key) "host key OK: %s"
> +ssh_connect_to_ssh(char *path, int flags, int mode) "opening file %s flags=0x%x creat_mode=0%o"
> +ssh_co_yield(int sock, void *rd_handler, void *wr_handler) "s->sock=%d rd_handler=%p wr_handler=%p"
> +ssh_co_yield_back(int sock) "s->sock=%d - back"
> +ssh_getlength(int64_t length) "length=%" PRIi64
> +ssh_co_create_opts(uint64_t size) "total_size=%" PRIu64
> +ssh_read(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
> +ssh_read_buf(void *buf, size_t size) "sftp_read buf=%p size=%zu"
> +ssh_read_return(size_t ret) "sftp_read returned %zd"
> +ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
> +ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
> +ssh_write_return(size_t ret) "sftp_write returned %zd"

%zu?

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

> +ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64
> 

Re: [Qemu-devel] [PATCH 3/4] block/file-posix: Convert from DPRINTF() macro to trace events

[Philippe Mathieu-Daudé]

On 12/12/18 8:40 PM, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

> ---
>  block/file-posix.c | 25 ++++++-------------------
>  block/trace-events |  7 +++++++
>  2 files changed, 13 insertions(+), 19 deletions(-)
> 
> diff --git a/block/file-posix.c b/block/file-posix.c
> index 07bbdab953..cf90899a6e 100644
> --- a/block/file-posix.c
> +++ b/block/file-posix.c
> @@ -102,19 +102,7 @@
>  #include <xfs/xfs.h>
>  #endif
>  
> -//#define DEBUG_BLOCK
> -
> -#ifdef DEBUG_BLOCK
> -# define DEBUG_BLOCK_PRINT 1
> -#else
> -# define DEBUG_BLOCK_PRINT 0
> -#endif
> -#define DPRINTF(fmt, ...) \
> -do { \
> -    if (DEBUG_BLOCK_PRINT) { \
> -        printf(fmt, ## __VA_ARGS__); \
> -    } \
> -} while (0)
> +#include "trace.h"
>  
>  /* OS X does not have O_DSYNC */
>  #ifndef O_DSYNC
> @@ -1386,7 +1374,7 @@ static int xfs_write_zeroes(BDRVRawState *s, int64_t offset, uint64_t bytes)
>  
>      if (xfsctl(NULL, s->fd, XFS_IOC_ZERO_RANGE, &fl) < 0) {
>          err = errno;
> -        DPRINTF("cannot write zero range (%s)\n", strerror(errno));
> +        trace_file_xfs_write_zeroes(strerror(errno));
>          return -err;
>      }
>  
> @@ -1405,7 +1393,7 @@ static int xfs_discard(BDRVRawState *s, int64_t offset, uint64_t bytes)
>  
>      if (xfsctl(NULL, s->fd, XFS_IOC_UNRESVSP64, &fl) < 0) {
>          err = errno;
> -        DPRINTF("cannot punch hole (%s)\n", strerror(errno));
> +        trace_file_xfs_discard(strerror(errno));
>          return -err;
>      }
>  
> @@ -2798,7 +2786,7 @@ static char *FindEjectableOpticalMedia(io_iterator_t *mediaIterator)
>  
>          /* If a match was found, leave the loop */
>          if (*mediaIterator != 0) {
> -            DPRINTF("Matching using %s\n", matching_array[index]);
> +            trace_file_FindEjectableOpticalMedia(matching_array[index]);
>              mediaType = g_strdup(matching_array[index]);
>              break;
>          }
> @@ -2858,7 +2846,7 @@ static bool setup_cdrom(char *bsd_path, Error **errp)
>      if (partition_found == false) {
>          error_setg(errp, "Failed to find a working partition on disc");
>      } else {
> -        DPRINTF("Using %s as optical disc\n", test_partition);
> +        trace_file_setup_cdrom(test_partition);
>          pstrcpy(bsd_path, MAXPATHLEN, test_partition);
>      }
>      return partition_found;
> @@ -2953,8 +2941,7 @@ static bool hdev_is_sg(BlockDriverState *bs)
>  
>      ret = ioctl(s->fd, SG_GET_SCSI_ID, &scsiid);
>      if (ret >= 0) {
> -        DPRINTF("SG device found: type=%d, version=%d\n",
> -            scsiid.scsi_type, sg_version);
> +        trace_file_hdev_is_sg(scsiid.scsi_type, sg_version);
>          return true;
>      }
>  
> diff --git a/block/trace-events b/block/trace-events
> index 5b83280b02..49f31966e7 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -182,3 +182,10 @@ curl_open(const char *file) "opening %s"
>  curl_open_size(uint64_t size) "size = %" PRIu64
>  curl_setup_preadv(uint64_t bytes, uint64_t start, const char *range) "reading %" PRIu64 " at %" PRIu64 " (%s)"
>  curl_close(void) "close"
> +
> +# block/file-posix.c
> +file_xfs_write_zeroes(const char *error) "cannot write zero range (%s)"
> +file_xfs_discard(const char* error) "cannot punch hole (%s)"
> +file_FindEjectableOpticalMedia(const char *media) "Matching using %s"
> +file_setup_cdrom(const char *partition) "Using %s as optical disc"
> +file_hdev_is_sg(int type, int version) "SG device found: type=%d, version=%d"
> 

Re: [Qemu-devel] [PATCH 4/4] block/sheepdog: Convert from DPRINTF() macro to trace events

[Philippe Mathieu-Daudé]

Hi Laurent,

On 12/12/18 8:40 PM, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  block/sheepdog.c   | 47 +++++++++++++++++-----------------------------
>  block/trace-events | 14 ++++++++++++++
>  2 files changed, 31 insertions(+), 30 deletions(-)
> 
> diff --git a/block/sheepdog.c b/block/sheepdog.c
> index 0125df9d49..a5000d271b 100644
> --- a/block/sheepdog.c
> +++ b/block/sheepdog.c
> @@ -28,6 +28,7 @@
>  #include "sysemu/block-backend.h"
>  #include "qemu/bitops.h"
>  #include "qemu/cutils.h"
> +#include "trace.h"
>  
>  #define SD_PROTO_VER 0x01
>  
> @@ -299,19 +300,6 @@ static inline size_t count_data_objs(const struct SheepdogInode *inode)
>                          (1UL << inode->block_size_shift));
>  }
>  
> -#undef DPRINTF
> -#ifdef DEBUG_SDOG
> -#define DEBUG_SDOG_PRINT 1
> -#else
> -#define DEBUG_SDOG_PRINT 0
> -#endif
> -#define DPRINTF(fmt, args...)                                           \
> -    do {                                                                \
> -        if (DEBUG_SDOG_PRINT) {                                         \
> -            fprintf(stderr, "%s %d: " fmt, __func__, __LINE__, ##args); \
> -        }                                                               \
> -    } while (0)
> -
>  typedef struct SheepdogAIOCB SheepdogAIOCB;
>  typedef struct BDRVSheepdogState BDRVSheepdogState;
>  
> @@ -750,7 +738,7 @@ static coroutine_fn void reconnect_to_sdog(void *opaque)
>          Error *local_err = NULL;
>          s->fd = get_sheep_fd(s, &local_err);
>          if (s->fd < 0) {
> -            DPRINTF("Wait for connection to be established\n");
> +            trace_sd_reconnect_to_sdog();
>              error_report_err(local_err);
>              qemu_co_sleep_ns(QEMU_CLOCK_REALTIME, 1000000000ULL);
>          }
> @@ -847,7 +835,7 @@ static void coroutine_fn aio_read_response(void *opaque)
>          break;
>      case AIOCB_FLUSH_CACHE:
>          if (rsp.result == SD_RES_INVALID_PARMS) {
> -            DPRINTF("disable cache since the server doesn't support it\n");
> +            trace_sd_aio_read_response();
>              s->cache_flags = SD_FLAG_CMD_DIRECT;
>              rsp.result = SD_RES_SUCCESS;
>          }
> @@ -1639,7 +1627,7 @@ static int sd_open(BlockDriverState *bs, QDict *options, int flags,
>      s->discard_supported = true;
>  
>      if (snap_id || tag[0]) {
> -        DPRINTF("%" PRIx32 " snapshot inode was open.\n", vid);
> +        trace_sd_open(vid);
>          s->is_snapshot = true;
>      }
>  
> @@ -2252,7 +2240,7 @@ static void sd_close(BlockDriverState *bs)
>      unsigned int wlen, rlen = 0;
>      int fd, ret;
>  
> -    DPRINTF("%s\n", s->name);
> +    trace_sd_close(s->name);
>  
>      fd = connect_to_sdog(s, &local_err);
>      if (fd < 0) {
> @@ -2429,7 +2417,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
>      char *buf;
>      bool deleted;
>  
> -    DPRINTF("%" PRIx32 " is snapshot.\n", s->inode.vdi_id);
> +    trace_sd_create_branch_snapshot(s->inode.vdi_id);
>  
>      buf = g_malloc(SD_INODE_SIZE);
>  
> @@ -2445,7 +2433,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
>          goto out;
>      }
>  
> -    DPRINTF("%" PRIx32 " is created.\n", vid);
> +    trace_sd_create_branch_created(vid);
>  
>      fd = connect_to_sdog(s, &local_err);
>      if (fd < 0) {
> @@ -2467,7 +2455,7 @@ static int sd_create_branch(BDRVSheepdogState *s)
>  
>      s->is_snapshot = false;
>      ret = 0;
> -    DPRINTF("%" PRIx32 " was newly created.\n", s->inode.vdi_id);
> +    trace_sd_create_branch_new(s->inode.vdi_id);
>  
>  out:
>      g_free(buf);
> @@ -2561,11 +2549,11 @@ static void coroutine_fn sd_co_rw_vector(SheepdogAIOCB *acb)
>          }
>  
>          if (create) {
> -            DPRINTF("update ino (%" PRIu32 ") %" PRIu64 " %" PRIu64 " %ld\n",
> -                    inode->vdi_id, oid,
> -                    vid_to_data_oid(inode->data_vdi_id[idx], idx), idx);
> +            trace_sd_co_rw_vector_update(inode->vdi_id, oid,
> +                                  vid_to_data_oid(inode->data_vdi_id[idx], idx),
> +                                  idx);
>              oid = vid_to_data_oid(inode->vdi_id, idx);
> -            DPRINTF("new oid %" PRIx64 "\n", oid);
> +            trace_sd_co_rw_vector_new(oid);
>          }
>  
>          aio_req = alloc_aio_req(s, acb, oid, len, offset, flags, create,
> @@ -2670,9 +2658,8 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
>      SheepdogInode *inode;
>      unsigned int datalen;
>  
> -    DPRINTF("sn_info: name %s id_str %s s: name %s vm_state_size %" PRId64 " "
> -            "is_snapshot %d\n", sn_info->name, sn_info->id_str,
> -            s->name, sn_info->vm_state_size, s->is_snapshot);
> +    trace_sd_snapshot_create_info(sn_info->name, sn_info->id_str, s->name,
> +                                  sn_info->vm_state_size, s->is_snapshot);
>  
>      if (s->is_snapshot) {
>          error_report("You can't create a snapshot of a snapshot VDI, "
> @@ -2681,7 +2668,7 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
>          return -EINVAL;
>      }
>  
> -    DPRINTF("%s %s\n", sn_info->name, sn_info->id_str);
> +    trace_sd_snapshot_create(sn_info->name, sn_info->id_str);
>  
>      s->inode.vm_state_size = sn_info->vm_state_size;
>      s->inode.vm_clock_nsec = sn_info->vm_clock_nsec;
> @@ -2726,8 +2713,8 @@ static int sd_snapshot_create(BlockDriverState *bs, QEMUSnapshotInfo *sn_info)
>      }
>  
>      memcpy(&s->inode, inode, datalen);
> -    DPRINTF("s->inode: name %s snap_id %x oid %x\n",
> -            s->inode.name, s->inode.snap_id, s->inode.vdi_id);
> +    trace_sd_snapshot_create_inode(s->inode.name, s->inode.snap_id,
> +                                   s->inode.vdi_id);
>  
>  cleanup:
>      g_free(inode);
> diff --git a/block/trace-events b/block/trace-events
> index 49f31966e7..7a92d7b3db 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -189,3 +189,17 @@ file_xfs_discard(const char* error) "cannot punch hole (%s)"
>  file_FindEjectableOpticalMedia(const char *media) "Matching using %s"
>  file_setup_cdrom(const char *partition) "Using %s as optical disc"
>  file_hdev_is_sg(int type, int version) "SG device found: type=%d, version=%d"
> +
> +# block/sheepdog.c
> +sd_reconnect_to_sdog(void) "Wait for connection to be established"

Can you use the 'sheepdog' prefix to avoid clashing with the 'sd' subsystem?

> +sd_aio_read_response(void) "disable cache since the server doesn't support it"
> +sd_open(uint32_t vid) "0x%" PRIx32 " snapshot inode was open."

We can drop the trailing dots.

> +sd_close(const char *name) "%s"
> +sd_create_branch_snapshot(uint32_t vdi) "0x%" PRIx32 " is snapshot."
> +sd_create_branch_created(uint32_t vdi) "0x%" PRIx32 " is created."
> +sd_create_branch_new(uint32_t vdi) "0x%" PRIx32 " was newly created."
> +sd_co_rw_vector_update(uint32_t vdi, uint64_t oid, uint64_t data, long idx) "update ino (%" PRIu32 ") %" PRIu64 " %" PRIu64 " %ld"
> +sd_co_rw_vector_new(uint64_t oid) "new oid 0x%" PRIx64
> +sd_snapshot_create_info(const char *sn_name, const char *id, const char *name, int64_t size, int is_snapshot) "sn_info: name %s id_str %s s: name %s vm_state_size %" PRId64 " " "is_snapshot %d"
> +sd_snapshot_create(const char *sn_name, const char *id) "%s %s"
> +sd_snapshot_create_inode(const char *name, uint32_t snap, uint32_t vdi) "s->inode: name %s snap_id 0x%x vdi 0x%x"
> 

With 'sheepdog' prefix:
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [Qemu-devel] [PATCH 2/4] block/curl: Convert from DPRINTF() macro to trace events

[Philippe Mathieu-Daudé]

On 12/12/18 8:40 PM, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  block/curl.c       | 29 ++++++++---------------------
>  block/trace-events |  9 +++++++++
>  2 files changed, 17 insertions(+), 21 deletions(-)
> 
> diff --git a/block/curl.c b/block/curl.c
> index db5d2bd8ef..b7ac265d3a 100644
> --- a/block/curl.c
> +++ b/block/curl.c
> @@ -32,22 +32,10 @@
>  #include "crypto/secret.h"
>  #include <curl/curl.h>
>  #include "qemu/cutils.h"
> +#include "trace.h"
>  
> -// #define DEBUG_CURL
>  // #define DEBUG_VERBOSE
>  
> -#ifdef DEBUG_CURL
> -#define DEBUG_CURL_PRINT 1
> -#else
> -#define DEBUG_CURL_PRINT 0
> -#endif
> -#define DPRINTF(fmt, ...)                                            \
> -    do {                                                             \
> -        if (DEBUG_CURL_PRINT) {                                      \
> -            fprintf(stderr, fmt, ## __VA_ARGS__);                    \
> -        }                                                            \
> -    } while (0)
> -
>  #if LIBCURL_VERSION_NUM >= 0x071000
>  /* The multi interface timer callback was introduced in 7.16.0 */
>  #define NEED_CURL_TIMER_CALLBACK
> @@ -154,7 +142,7 @@ static int curl_timer_cb(CURLM *multi, long timeout_ms, void *opaque)
>  {
>      BDRVCURLState *s = opaque;
>  
> -    DPRINTF("CURL: timer callback timeout_ms %ld\n", timeout_ms);
> +    trace_curl_timer_cb(timeout_ms);
>      if (timeout_ms == -1) {
>          timer_del(&s->timer);
>      } else {
> @@ -193,7 +181,7 @@ static int curl_sock_cb(CURL *curl, curl_socket_t fd, int action,
>      }
>      socket = NULL;
>  
> -    DPRINTF("CURL (AIO): Sock action %d on fd %d\n", action, (int)fd);
> +    trace_curl_sock_cb(action, (int)fd);
>      switch (action) {
>          case CURL_POLL_IN:
>              aio_set_fd_handler(s->aio_context, fd, false,
> @@ -238,7 +226,7 @@ static size_t curl_read_cb(void *ptr, size_t size, size_t nmemb, void *opaque)
>      size_t realsize = size * nmemb;
>      int i;
>  
> -    DPRINTF("CURL: Just reading %zd bytes\n", realsize);
> +    trace_curl_read_cb(realsize);
>  
>      if (!s || !s->orig_buf) {
>          goto read_end;
> @@ -777,7 +765,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
>          }
>      }
>  
> -    DPRINTF("CURL: Opening %s\n", file);
> +    trace_curl_open(file);
>      qemu_co_queue_init(&s->free_state_waitq);
>      s->aio_context = bdrv_get_aio_context(bs);
>      s->url = g_strdup(file);
> @@ -830,7 +818,7 @@ static int curl_open(BlockDriverState *bs, QDict *options, int flags,
>                  "Server does not support 'range' (byte ranges).");
>          goto out;
>      }
> -    DPRINTF("CURL: Size = %" PRIu64 "\n", s->len);
> +    trace_curl_open_size(s->len);
>  
>      qemu_mutex_lock(&s->mutex);
>      curl_clean_state(state);
> @@ -908,8 +896,7 @@ static void curl_setup_preadv(BlockDriverState *bs, CURLAIOCB *acb)
>      state->acb[0] = acb;
>  
>      snprintf(state->range, 127, "%" PRIu64 "-%" PRIu64, start, end);
> -    DPRINTF("CURL (AIO): Reading %" PRIu64 " at %" PRIu64 " (%s)\n",
> -            acb->bytes, start, state->range);
> +    trace_curl_setup_preadv(acb->bytes, start, state->range);
>      curl_easy_setopt(state->curl, CURLOPT_RANGE, state->range);
>  
>      curl_multi_add_handle(s->multi, state->curl);
> @@ -943,7 +930,7 @@ static void curl_close(BlockDriverState *bs)
>  {
>      BDRVCURLState *s = bs->opaque;
>  
> -    DPRINTF("CURL: Close\n");
> +    trace_curl_close();
>      curl_detach_aio_context(bs);
>      qemu_mutex_destroy(&s->mutex);
>  
> diff --git a/block/trace-events b/block/trace-events
> index b13b1e9706..5b83280b02 100644
> --- a/block/trace-events
> +++ b/block/trace-events
> @@ -173,3 +173,12 @@ ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
>  ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
>  ssh_write_return(size_t ret) "sftp_write returned %zd"
>  ssh_seek(uint64_t offset) "seeking to offset=%" PRIi64
> +
> +# block/curl.c
> +curl_timer_cb(long timeout_ms) "timer callback timeout_ms %ld"
> +curl_sock_cb(int action, int fd) "sock action %d on fd %d"
> +curl_read_cb(size_t realsize) "just reading %zd bytes"

%zu

> +curl_open(const char *file) "opening %s"
> +curl_open_size(uint64_t size) "size = %" PRIu64
> +curl_setup_preadv(uint64_t bytes, uint64_t start, const char *range) "reading %" PRIu64 " at %" PRIu64 " (%s)"
> +curl_close(void) "close"
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>