Pablo Greco e6a3ae
From f087aa3581b13254e4de34784631f1852a9ddbec Mon Sep 17 00:00:00 2001
Pablo Greco e6a3ae
From: Pino Toscano <ptoscano@redhat.com>
Pablo Greco e6a3ae
Date: Mon, 8 Jul 2019 15:25:52 +0100
Pablo Greco e6a3ae
Subject: [PATCH 06/39] block/ssh: Convert from DPRINTF() macro to trace events
Pablo Greco e6a3ae
MIME-Version: 1.0
Pablo Greco e6a3ae
Content-Type: text/plain; charset=UTF-8
Pablo Greco e6a3ae
Content-Transfer-Encoding: 8bit
Pablo Greco e6a3ae
Pablo Greco e6a3ae
RH-Author: Pino Toscano <ptoscano@redhat.com>
Pablo Greco e6a3ae
Message-id: <20190708152601.21123-2-ptoscano@redhat.com>
Pablo Greco e6a3ae
Patchwork-id: 89415
Pablo Greco e6a3ae
O-Subject: [RHEL-8.1.0 qemu-kvm PATCH v3 01/10] block/ssh: Convert from DPRINTF() macro to trace events
Pablo Greco e6a3ae
Bugzilla: 1513367
Pablo Greco e6a3ae
RH-Acked-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Pablo Greco e6a3ae
RH-Acked-by: Max Reitz <mreitz@redhat.com>
Pablo Greco e6a3ae
RH-Acked-by: Miroslav Rezanina <mrezanin@redhat.com>
Pablo Greco e6a3ae
RH-Acked-by: Markus Armbruster <armbru@redhat.com>
Pablo Greco e6a3ae
Pablo Greco e6a3ae
From: Laurent Vivier <lvivier@redhat.com>
Pablo Greco e6a3ae
Pablo Greco e6a3ae
Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Pablo Greco e6a3ae
Reviewed-by: Richard W.M. Jones <rjones@redhat.com>
Pablo Greco e6a3ae
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Pablo Greco e6a3ae
Message-id: 20181213162727.17438-2-lvivier@redhat.com
Pablo Greco e6a3ae
[mreitz: Fixed type of ssh_{read,write}_return's parameter to be ssize_t
Pablo Greco e6a3ae
         instead of size_t]
Pablo Greco e6a3ae
Signed-off-by: Max Reitz <mreitz@redhat.com>
Pablo Greco e6a3ae
(cherry picked from commit 023908a24de4f264dbcd22352e8a304424005bd4)
Pablo Greco e6a3ae
Signed-off-by: Pino Toscano <ptoscano@redhat.com>
Pablo Greco e6a3ae
Pablo Greco e6a3ae
Signed-off-by: Danilo C. L. de Paula <ddepaula@redhat.com>
Pablo Greco e6a3ae
---
Pablo Greco e6a3ae
 block/ssh.c        | 46 +++++++++++++++++-----------------------------
Pablo Greco e6a3ae
 block/trace-events | 17 +++++++++++++++++
Pablo Greco e6a3ae
 2 files changed, 34 insertions(+), 29 deletions(-)
Pablo Greco e6a3ae
Pablo Greco e6a3ae
diff --git a/block/ssh.c b/block/ssh.c
Pablo Greco e6a3ae
index 6a55d82..dfb3e3c 100644
Pablo Greco e6a3ae
--- a/block/ssh.c
Pablo Greco e6a3ae
+++ b/block/ssh.c
Pablo Greco e6a3ae
@@ -41,27 +41,17 @@
Pablo Greco e6a3ae
 #include "qapi/qmp/qstring.h"
Pablo Greco e6a3ae
 #include "qapi/qobject-input-visitor.h"
Pablo Greco e6a3ae
 #include "qapi/qobject-output-visitor.h"
Pablo Greco e6a3ae
+#include "trace.h"
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-/* DEBUG_SSH=1 enables the DPRINTF (debugging printf) statements in
Pablo Greco e6a3ae
- * this block driver code.
Pablo Greco e6a3ae
- *
Pablo Greco e6a3ae
+/*
Pablo Greco e6a3ae
  * TRACE_LIBSSH2=<bitmask> enables tracing in libssh2 itself.  Note
Pablo Greco e6a3ae
  * that this requires that libssh2 was specially compiled with the
Pablo Greco e6a3ae
  * `./configure --enable-debug' option, so most likely you will have
Pablo Greco e6a3ae
  * to compile it yourself.  The meaning of <bitmask> is described
Pablo Greco e6a3ae
  * here: http://www.libssh2.org/libssh2_trace.html
Pablo Greco e6a3ae
  */
Pablo Greco e6a3ae
-#define DEBUG_SSH     0
Pablo Greco e6a3ae
 #define TRACE_LIBSSH2 0 /* or try: LIBSSH2_TRACE_SFTP */
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-#define DPRINTF(fmt, ...)                           \
Pablo Greco e6a3ae
-    do {                                            \
Pablo Greco e6a3ae
-        if (DEBUG_SSH) {                            \
Pablo Greco e6a3ae
-            fprintf(stderr, "ssh: %-15s " fmt "\n", \
Pablo Greco e6a3ae
-                    __func__, ##__VA_ARGS__);       \
Pablo Greco e6a3ae
-        }                                           \
Pablo Greco e6a3ae
-    } while (0)
Pablo Greco e6a3ae
-
Pablo Greco e6a3ae
 typedef struct BDRVSSHState {
Pablo Greco e6a3ae
     /* Coroutine. */
Pablo Greco e6a3ae
     CoMutex lock;
Pablo Greco e6a3ae
@@ -336,7 +326,7 @@ static int check_host_key_knownhosts(BDRVSSHState *s,
Pablo Greco e6a3ae
     switch (r) {
Pablo Greco e6a3ae
     case LIBSSH2_KNOWNHOST_CHECK_MATCH:
Pablo Greco e6a3ae
         /* OK */
Pablo Greco e6a3ae
-        DPRINTF("host key OK: %s", found->key);
Pablo Greco e6a3ae
+        trace_ssh_check_host_key_knownhosts(found->key);
Pablo Greco e6a3ae
         break;
Pablo Greco e6a3ae
     case LIBSSH2_KNOWNHOST_CHECK_MISMATCH:
Pablo Greco e6a3ae
         ret = -EINVAL;
Pablo Greco e6a3ae
@@ -721,8 +711,7 @@ static int connect_to_ssh(BDRVSSHState *s, BlockdevOptionsSsh *opts,
Pablo Greco e6a3ae
     }
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     /* Open the remote file. */
Pablo Greco e6a3ae
-    DPRINTF("opening file %s flags=0x%x creat_mode=0%o",
Pablo Greco e6a3ae
-            opts->path, ssh_flags, creat_mode);
Pablo Greco e6a3ae
+    trace_ssh_connect_to_ssh(opts->path, ssh_flags, creat_mode);
Pablo Greco e6a3ae
     s->sftp_handle = libssh2_sftp_open(s->sftp, opts->path, ssh_flags,
Pablo Greco e6a3ae
                                        creat_mode);
Pablo Greco e6a3ae
     if (!s->sftp_handle) {
Pablo Greco e6a3ae
@@ -890,7 +879,7 @@ static int coroutine_fn ssh_co_create_opts(const char *filename, QemuOpts *opts,
Pablo Greco e6a3ae
     /* Get desired file size. */
Pablo Greco e6a3ae
     ssh_opts->size = ROUND_UP(qemu_opt_get_size_del(opts, BLOCK_OPT_SIZE, 0),
Pablo Greco e6a3ae
                               BDRV_SECTOR_SIZE);
Pablo Greco e6a3ae
-    DPRINTF("total_size=%" PRIi64, ssh_opts->size);
Pablo Greco e6a3ae
+    trace_ssh_co_create_opts(ssh_opts->size);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     uri_options = qdict_new();
Pablo Greco e6a3ae
     ret = parse_uri(filename, uri_options, errp);
Pablo Greco e6a3ae
@@ -946,7 +935,7 @@ static void restart_coroutine(void *opaque)
Pablo Greco e6a3ae
     BDRVSSHState *s = bs->opaque;
Pablo Greco e6a3ae
     AioContext *ctx = bdrv_get_aio_context(bs);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-    DPRINTF("co=%p", restart->co);
Pablo Greco e6a3ae
+    trace_ssh_restart_coroutine(restart->co);
Pablo Greco e6a3ae
     aio_set_fd_handler(ctx, s->sock, false, NULL, NULL, NULL, NULL);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     aio_co_wake(restart->co);
Pablo Greco e6a3ae
@@ -974,13 +963,12 @@ static coroutine_fn void co_yield(BDRVSSHState *s, BlockDriverState *bs)
Pablo Greco e6a3ae
         wr_handler = restart_coroutine;
Pablo Greco e6a3ae
     }
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-    DPRINTF("s->sock=%d rd_handler=%p wr_handler=%p", s->sock,
Pablo Greco e6a3ae
-            rd_handler, wr_handler);
Pablo Greco e6a3ae
+    trace_ssh_co_yield(s->sock, rd_handler, wr_handler);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     aio_set_fd_handler(bdrv_get_aio_context(bs), s->sock,
Pablo Greco e6a3ae
                        false, rd_handler, wr_handler, NULL, &restart);
Pablo Greco e6a3ae
     qemu_coroutine_yield();
Pablo Greco e6a3ae
-    DPRINTF("s->sock=%d - back", s->sock);
Pablo Greco e6a3ae
+    trace_ssh_co_yield_back(s->sock);
Pablo Greco e6a3ae
 }
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
 /* SFTP has a function `libssh2_sftp_seek64' which seeks to a position
Pablo Greco e6a3ae
@@ -1003,7 +991,7 @@ static void ssh_seek(BDRVSSHState *s, int64_t offset, int flags)
Pablo Greco e6a3ae
     bool force = (flags & SSH_SEEK_FORCE) != 0;
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     if (force || op_read != s->offset_op_read || offset != s->offset) {
Pablo Greco e6a3ae
-        DPRINTF("seeking to offset=%" PRIi64, offset);
Pablo Greco e6a3ae
+        trace_ssh_seek(offset);
Pablo Greco e6a3ae
         libssh2_sftp_seek64(s->sftp_handle, offset);
Pablo Greco e6a3ae
         s->offset = offset;
Pablo Greco e6a3ae
         s->offset_op_read = op_read;
Pablo Greco e6a3ae
@@ -1019,7 +1007,7 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
Pablo Greco e6a3ae
     char *buf, *end_of_vec;
Pablo Greco e6a3ae
     struct iovec *i;
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
Pablo Greco e6a3ae
+    trace_ssh_read(offset, size);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     ssh_seek(s, offset, SSH_SEEK_READ);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
@@ -1038,9 +1026,9 @@ static coroutine_fn int ssh_read(BDRVSSHState *s, BlockDriverState *bs,
Pablo Greco e6a3ae
      */
Pablo Greco e6a3ae
     for (got = 0; got < size; ) {
Pablo Greco e6a3ae
     again:
Pablo Greco e6a3ae
-        DPRINTF("sftp_read buf=%p size=%zu", buf, end_of_vec - buf);
Pablo Greco e6a3ae
+        trace_ssh_read_buf(buf, end_of_vec - buf);
Pablo Greco e6a3ae
         r = libssh2_sftp_read(s->sftp_handle, buf, end_of_vec - buf);
Pablo Greco e6a3ae
-        DPRINTF("sftp_read returned %zd", r);
Pablo Greco e6a3ae
+        trace_ssh_read_return(r);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
         if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
Pablo Greco e6a3ae
             co_yield(s, bs);
Pablo Greco e6a3ae
@@ -1094,7 +1082,7 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
Pablo Greco e6a3ae
     char *buf, *end_of_vec;
Pablo Greco e6a3ae
     struct iovec *i;
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-    DPRINTF("offset=%" PRIi64 " size=%zu", offset, size);
Pablo Greco e6a3ae
+    trace_ssh_write(offset, size);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     ssh_seek(s, offset, SSH_SEEK_WRITE);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
@@ -1108,9 +1096,9 @@ static int ssh_write(BDRVSSHState *s, BlockDriverState *bs,
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     for (written = 0; written < size; ) {
Pablo Greco e6a3ae
     again:
Pablo Greco e6a3ae
-        DPRINTF("sftp_write buf=%p size=%zu", buf, end_of_vec - buf);
Pablo Greco e6a3ae
+        trace_ssh_write_buf(buf, end_of_vec - buf);
Pablo Greco e6a3ae
         r = libssh2_sftp_write(s->sftp_handle, buf, end_of_vec - buf);
Pablo Greco e6a3ae
-        DPRINTF("sftp_write returned %zd", r);
Pablo Greco e6a3ae
+        trace_ssh_write_return(r);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
         if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
Pablo Greco e6a3ae
             co_yield(s, bs);
Pablo Greco e6a3ae
@@ -1185,7 +1173,7 @@ static coroutine_fn int ssh_flush(BDRVSSHState *s, BlockDriverState *bs)
Pablo Greco e6a3ae
 {
Pablo Greco e6a3ae
     int r;
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
-    DPRINTF("fsync");
Pablo Greco e6a3ae
+    trace_ssh_flush();
Pablo Greco e6a3ae
  again:
Pablo Greco e6a3ae
     r = libssh2_sftp_fsync(s->sftp_handle);
Pablo Greco e6a3ae
     if (r == LIBSSH2_ERROR_EAGAIN || r == LIBSSH2_ERROR_TIMEOUT) {
Pablo Greco e6a3ae
@@ -1236,7 +1224,7 @@ static int64_t ssh_getlength(BlockDriverState *bs)
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     /* Note we cannot make a libssh2 call here. */
Pablo Greco e6a3ae
     length = (int64_t) s->attrs.filesize;
Pablo Greco e6a3ae
-    DPRINTF("length=%" PRIi64, length);
Pablo Greco e6a3ae
+    trace_ssh_getlength(length);
Pablo Greco e6a3ae
 
Pablo Greco e6a3ae
     return length;
Pablo Greco e6a3ae
 }
Pablo Greco e6a3ae
diff --git a/block/trace-events b/block/trace-events
Pablo Greco e6a3ae
index c35287b..4c69548 100644
Pablo Greco e6a3ae
--- a/block/trace-events
Pablo Greco e6a3ae
+++ b/block/trace-events
Pablo Greco e6a3ae
@@ -150,3 +150,20 @@ nvme_free_req_queue_wait(void *q) "q %p"
Pablo Greco e6a3ae
 nvme_cmd_map_qiov(void *s, void *cmd, void *req, void *qiov, int entries) "s %p cmd %p req %p qiov %p entries %d"
Pablo Greco e6a3ae
 nvme_cmd_map_qiov_pages(void *s, int i, uint64_t page) "s %p page[%d] 0x%"PRIx64
Pablo Greco e6a3ae
 nvme_cmd_map_qiov_iov(void *s, int i, void *page, int pages) "s %p iov[%d] %p pages %d"
Pablo Greco e6a3ae
+
Pablo Greco e6a3ae
+# block/ssh.c
Pablo Greco e6a3ae
+ssh_restart_coroutine(void *co) "co=%p"
Pablo Greco e6a3ae
+ssh_flush(void) "fsync"
Pablo Greco e6a3ae
+ssh_check_host_key_knownhosts(const char *key) "host key OK: %s"
Pablo Greco e6a3ae
+ssh_connect_to_ssh(char *path, int flags, int mode) "opening file %s flags=0x%x creat_mode=0%o"
Pablo Greco e6a3ae
+ssh_co_yield(int sock, void *rd_handler, void *wr_handler) "s->sock=%d rd_handler=%p wr_handler=%p"
Pablo Greco e6a3ae
+ssh_co_yield_back(int sock) "s->sock=%d - back"
Pablo Greco e6a3ae
+ssh_getlength(int64_t length) "length=%" PRIi64
Pablo Greco e6a3ae
+ssh_co_create_opts(uint64_t size) "total_size=%" PRIu64
Pablo Greco e6a3ae
+ssh_read(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
Pablo Greco e6a3ae
+ssh_read_buf(void *buf, size_t size) "sftp_read buf=%p size=%zu"
Pablo Greco e6a3ae
+ssh_read_return(ssize_t ret) "sftp_read returned %zd"
Pablo Greco e6a3ae
+ssh_write(int64_t offset, size_t size) "offset=%" PRIi64 " size=%zu"
Pablo Greco e6a3ae
+ssh_write_buf(void *buf, size_t size) "sftp_write buf=%p size=%zu"
Pablo Greco e6a3ae
+ssh_write_return(ssize_t ret) "sftp_write returned %zd"
Pablo Greco e6a3ae
+ssh_seek(int64_t offset) "seeking to offset=%" PRIi64
Pablo Greco e6a3ae
-- 
Pablo Greco e6a3ae
1.8.3.1
Pablo Greco e6a3ae