[Qemu-devel] [PATCH v2 0/2] scsi: Convert from DPRINTF() macro to trace events

[Qemu-devel] [PATCH v2 0/2] scsi: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Convert the last two files in hw/scsi.

v2: call directly trace_scsi_disk_new_request(), don't pass
    it in the argument

Laurent Vivier (2):
  scsi-disk: Convert from DPRINTF() macro to trace events
  scsi-generic: Convert from DPRINTF() macro to trace events

 hw/scsi/scsi-disk.c    | 103 ++++++++++++++++++++---------------------
 hw/scsi/scsi-generic.c |  56 +++++++++++-----------
 hw/scsi/trace-events   |  40 ++++++++++++++++
 3 files changed, 116 insertions(+), 83 deletions(-)

-- 
2.19.2

[Qemu-devel] [PATCH v2 1/2] scsi-disk: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Tested-by: Philippe Mathieu-Daudé <philmd@redhat.com>
---

Notes:
    v2: call directly trace_scsi_disk_new_request(), don't pass
        it in the arguments

 hw/scsi/scsi-disk.c  | 103 +++++++++++++++++++++----------------------
 hw/scsi/trace-events |  29 ++++++++++++
 2 files changed, 79 insertions(+), 53 deletions(-)

diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c
index 0e9027c8f3..6524360114 100644
--- a/hw/scsi/scsi-disk.c
+++ b/hw/scsi/scsi-disk.c
@@ -19,15 +19,6 @@
  * the host adapter emulator.
  */
 
-//#define DEBUG_SCSI
-
-#ifdef DEBUG_SCSI
-#define DPRINTF(fmt, ...) \
-do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) do {} while(0)
-#endif
-
 #include "qemu/osdep.h"
 #include "qemu/units.h"
 #include "qapi/error.h"
@@ -41,6 +32,7 @@ do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0)
 #include "hw/block/block.h"
 #include "sysemu/dma.h"
 #include "qemu/cutils.h"
+#include "trace.h"
 
 #ifdef __linux
 #include <scsi/sg.h>
@@ -128,8 +120,8 @@ static void scsi_free_request(SCSIRequest *req)
 /* Helper function for command completion with sense.  */
 static void scsi_check_condition(SCSIDiskReq *r, SCSISense sense)
 {
-    DPRINTF("Command complete tag=0x%x sense=%d/%d/%d\n",
-            r->req.tag, sense.key, sense.asc, sense.ascq);
+    trace_scsi_disk_check_condition(r->req.tag, sense.key, sense.asc,
+                                    sense.ascq);
     scsi_req_build_sense(&r->req, sense);
     scsi_req_complete(&r->req, CHECK_CONDITION);
 }
@@ -317,7 +309,7 @@ static void scsi_read_complete(void * opaque, int ret)
     }
 
     block_acct_done(blk_get_stats(s->qdev.conf.blk), &r->acct);
-    DPRINTF("Data ready tag=0x%x len=%zd\n", r->req.tag, r->qiov.size);
+    trace_scsi_disk_read_complete(r->req.tag, r->qiov.size);
 
     n = r->qiov.size / 512;
     r->sector += n;
@@ -388,7 +380,7 @@ static void scsi_read_data(SCSIRequest *req)
     SCSIDiskState *s = DO_UPCAST(SCSIDiskState, qdev, r->req.dev);
     bool first;
 
-    DPRINTF("Read sector_count=%d\n", r->sector_count);
+    trace_scsi_disk_read_data_count(r->sector_count);
     if (r->sector_count == 0) {
         /* This also clears the sense buffer for REQUEST SENSE.  */
         scsi_req_complete(&r->req, GOOD);
@@ -401,7 +393,7 @@ static void scsi_read_data(SCSIRequest *req)
     /* The request is used as the AIO opaque value, so add a ref.  */
     scsi_req_ref(&r->req);
     if (r->req.cmd.mode == SCSI_XFER_TO_DEV) {
-        DPRINTF("Data transfer direction invalid\n");
+        trace_scsi_disk_read_data_invalid();
         scsi_read_complete(r, -EINVAL);
         return;
     }
@@ -502,7 +494,7 @@ static void scsi_write_complete_noio(SCSIDiskReq *r, int ret)
         return;
     } else {
         scsi_init_iovec(r, SCSI_DMA_BUF_SIZE);
-        DPRINTF("Write complete tag=0x%x more=%zd\n", r->req.tag, r->qiov.size);
+        trace_scsi_disk_write_complete_noio(r->req.tag, r->qiov.size);
         scsi_req_data(&r->req, r->qiov.size);
     }
 
@@ -540,7 +532,7 @@ static void scsi_write_data(SCSIRequest *req)
     /* The request is used as the AIO opaque value, so add a ref.  */
     scsi_req_ref(&r->req);
     if (r->req.cmd.mode != SCSI_XFER_TO_DEV) {
-        DPRINTF("Data transfer direction invalid\n");
+        trace_scsi_disk_write_data_invalid();
         scsi_write_complete_noio(r, -EINVAL);
         return;
     }
@@ -605,8 +597,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf)
     switch (page_code) {
     case 0x00: /* Supported page codes, mandatory */
     {
-        DPRINTF("Inquiry EVPD[Supported pages] "
-                "buffer size %zd\n", req->cmd.xfer);
+        trace_scsi_disk_emulate_vpd_page_00(req->cmd.xfer);
         outbuf[buflen++] = 0x00; /* list of supported pages (this page) */
         if (s->serial) {
             outbuf[buflen++] = 0x80; /* unit serial number */
@@ -624,7 +615,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf)
         int l;
 
         if (!s->serial) {
-            DPRINTF("Inquiry (EVPD[Serial number] not supported\n");
+            trace_scsi_disk_emulate_vpd_page_80_not_supported();
             return -1;
         }
 
@@ -633,8 +624,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf)
             l = 36;
         }
 
-        DPRINTF("Inquiry EVPD[Serial number] "
-                "buffer size %zd\n", req->cmd.xfer);
+        trace_scsi_disk_emulate_vpd_page_80(req->cmd.xfer);
         memcpy(outbuf + buflen, s->serial, l);
         buflen += l;
         break;
@@ -649,8 +639,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf)
         if (id_len > max_len) {
             id_len = max_len;
         }
-        DPRINTF("Inquiry EVPD[Device identification] "
-                "buffer size %zd\n", req->cmd.xfer);
+        trace_scsi_disk_emulate_vpd_page_83(req->cmd.xfer);
 
         outbuf[buflen++] = 0x2; /* ASCII */
         outbuf[buflen++] = 0;   /* not officially assigned */
@@ -695,8 +684,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf)
         SCSIBlockLimits bl = {};
 
         if (s->qdev.type == TYPE_ROM) {
-            DPRINTF("Inquiry (EVPD[%02X] not supported for CDROM\n",
-                    page_code);
+            trace_scsi_disk_emulate_vpd_page_b0_not_supported();
             return -1;
         }
         bl.wsnz = 1;
@@ -1243,8 +1231,9 @@ static int scsi_disk_emulate_mode_sense(SCSIDiskReq *r, uint8_t *outbuf)
     dbd = (r->req.cmd.buf[1] & 0x8) != 0;
     page = r->req.cmd.buf[2] & 0x3f;
     page_control = (r->req.cmd.buf[2] & 0xc0) >> 6;
-    DPRINTF("Mode Sense(%d) (page %d, xfer %zd, page_control %d)\n",
-        (r->req.cmd.buf[0] == MODE_SENSE) ? 6 : 10, page, r->req.cmd.xfer, page_control);
+
+    trace_scsi_disk_emulate_mode_sense((r->req.cmd.buf[0] == MODE_SENSE) ? 6 :
+                                       10, page, r->req.cmd.xfer, page_control);
     memset(outbuf, 0, r->req.cmd.xfer);
     p = outbuf;
 
@@ -1336,7 +1325,7 @@ static int scsi_disk_emulate_read_toc(SCSIRequest *req, uint8_t *outbuf)
     format = req->cmd.buf[2] & 0xf;
     start_track = req->cmd.buf[6];
     blk_get_geometry(s->qdev.conf.blk, &nb_sectors);
-    DPRINTF("Read TOC (track %d format %d msf %d)\n", start_track, format, msf >> 1);
+    trace_scsi_disk_emulate_read_toc(start_track, format, msf >> 1);
     nb_sectors /= s->qdev.blocksize / 512;
     switch (format) {
     case 0:
@@ -1395,7 +1384,7 @@ static void scsi_disk_emulate_read_data(SCSIRequest *req)
     int buflen = r->iov.iov_len;
 
     if (buflen) {
-        DPRINTF("Read buf_len=%d\n", buflen);
+        trace_scsi_disk_emulate_read_data(buflen);
         r->iov.iov_len = 0;
         r->started = true;
         scsi_req_data(&r->req, buflen);
@@ -1814,7 +1803,7 @@ static void scsi_disk_emulate_write_data(SCSIRequest *req)
 
     if (r->iov.iov_len) {
         int buflen = r->iov.iov_len;
-        DPRINTF("Write buf_len=%d\n", buflen);
+        trace_scsi_disk_emulate_write_data(buflen);
         r->iov.iov_len = 0;
         scsi_req_data(&r->req, buflen);
         return;
@@ -2023,7 +2012,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf)
     case SERVICE_ACTION_IN_16:
         /* Service Action In subcommands. */
         if ((req->cmd.buf[1] & 31) == SAI_READ_CAPACITY_16) {
-            DPRINTF("SAI READ CAPACITY(16)\n");
+            trace_scsi_disk_emulate_command_SAI_16();
             memset(outbuf, 0, req->cmd.xfer);
             blk_get_geometry(s->qdev.conf.blk, &nb_sectors);
             if (!nb_sectors) {
@@ -2061,7 +2050,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf)
             /* Protection, exponent and lowest lba field left blank. */
             break;
         }
-        DPRINTF("Unsupported Service Action In\n");
+        trace_scsi_disk_emulate_command_SAI_unsupported();
         goto illegal_request;
     case SYNCHRONIZE_CACHE:
         /* The request is used as the AIO opaque value, so add a ref.  */
@@ -2071,37 +2060,36 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf)
         r->req.aiocb = blk_aio_flush(s->qdev.conf.blk, scsi_aio_complete, r);
         return 0;
     case SEEK_10:
-        DPRINTF("Seek(10) (sector %" PRId64 ")\n", r->req.cmd.lba);
+        trace_scsi_disk_emulate_command_SEEK_10(r->req.cmd.lba);
         if (r->req.cmd.lba > s->qdev.max_lba) {
             goto illegal_lba;
         }
         break;
     case MODE_SELECT:
-        DPRINTF("Mode Select(6) (len %lu)\n", (unsigned long)r->req.cmd.xfer);
+        trace_scsi_disk_emulate_command_MODE_SELECT(r->req.cmd.xfer);
         break;
     case MODE_SELECT_10:
-        DPRINTF("Mode Select(10) (len %lu)\n", (unsigned long)r->req.cmd.xfer);
+        trace_scsi_disk_emulate_command_MODE_SELECT_10(r->req.cmd.xfer);
         break;
     case UNMAP:
-        DPRINTF("Unmap (len %lu)\n", (unsigned long)r->req.cmd.xfer);
+        trace_scsi_disk_emulate_command_UNMAP(r->req.cmd.xfer);
         break;
     case VERIFY_10:
     case VERIFY_12:
     case VERIFY_16:
-        DPRINTF("Verify (bytchk %d)\n", (req->cmd.buf[1] >> 1) & 3);
+        trace_scsi_disk_emulate_command_VERIFY((req->cmd.buf[1] >> 1) & 3);
         if (req->cmd.buf[1] & 6) {
             goto illegal_request;
         }
         break;
     case WRITE_SAME_10:
     case WRITE_SAME_16:
-        DPRINTF("WRITE SAME %d (len %lu)\n",
-                req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16,
-                (unsigned long)r->req.cmd.xfer);
+        trace_scsi_disk_emulate_command_WRITE_SAME(
+                req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, r->req.cmd.xfer);
         break;
     default:
-        DPRINTF("Unknown SCSI command (%2.2x=%s)\n", buf[0],
-                scsi_command_name(buf[0]));
+        trace_scsi_disk_emulate_command_UNKNOWN(buf[0],
+                                                scsi_command_name(buf[0]));
         scsi_check_condition(r, SENSE_CODE(INVALID_OPCODE));
         return 0;
     }
@@ -2154,7 +2142,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf)
     case READ_10:
     case READ_12:
     case READ_16:
-        DPRINTF("Read (sector %" PRId64 ", count %u)\n", r->req.cmd.lba, len);
+        trace_scsi_disk_dma_command_READ(r->req.cmd.lba, len);
         /* Protection information is not supported.  For SCSI versions 2 and
          * older (as determined by snooping the guest's INQUIRY commands),
          * there is no RD/WR/VRPROTECT, so skip this check in these versions.
@@ -2179,7 +2167,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf)
             scsi_check_condition(r, SENSE_CODE(WRITE_PROTECTED));
             return 0;
         }
-        DPRINTF("Write %s(sector %" PRId64 ", count %u)\n",
+        trace_scsi_disk_dma_command_WRITE(
                 (command & 0xe) == 0xe ? "And Verify " : "",
                 r->req.cmd.lba, len);
         /* fall through */
@@ -2497,6 +2485,22 @@ static const SCSIReqOps *const scsi_disk_reqops_dispatch[256] = {
     [WRITE_VERIFY_16]                 = &scsi_disk_dma_reqops,
 };
 
+static void scsi_disk_new_request_dump(uint32_t lun, uint32_t tag, uint8_t *buf)
+{
+    int i;
+    int len = scsi_cdb_length(buf);
+    char *line_buffer, *p;
+
+    line_buffer = g_malloc(len * 5 + 1);
+
+    for (i = 0, p = line_buffer; i < len; i++) {
+        p += sprintf(p, " 0x%02x", buf[i]);
+    }
+    trace_scsi_disk_new_request(lun, tag, line_buffer);
+
+    g_free(line_buffer);
+}
+
 static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun,
                                      uint8_t *buf, void *hba_private)
 {
@@ -2512,16 +2516,9 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun,
     }
     req = scsi_req_alloc(ops, &s->qdev, tag, lun, hba_private);
 
-#ifdef DEBUG_SCSI
-    DPRINTF("Command: lun=%d tag=0x%x data=0x%02x", lun, tag, buf[0]);
-    {
-        int i;
-        for (i = 1; i < scsi_cdb_length(buf); i++) {
-            printf(" 0x%02x", buf[i]);
-        }
-        printf("\n");
+    if (trace_event_get_state_backends(TRACE_SCSI_DISK_NEW_REQUEST)) {
+        scsi_disk_new_request_dump(lun, tag, buf);
     }
-#endif
 
     return req;
 }
diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index 0fb6a99616..e9625f790c 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -291,3 +291,32 @@ lsi_execute_script_stop(void) "SCRIPTS execution stopped"
 lsi_awoken(void) "Woken by SIGP"
 lsi_reg_read(const char *name, int offset, uint8_t ret) "Read reg %s 0x%x = 0x%02x"
 lsi_reg_write(const char *name, int offset, uint8_t val) "Write reg %s 0x%x = 0x%02x"
+
+# hw/scsi/scsi-disk.c
+scsi_disk_check_condition(uint32_t tag, uint8_t key, uint8_t asc, uint8_t ascq) "Command complete tag=0x%x sense=%d/%d/%d"
+scsi_disk_read_complete(uint32_t tag, size_t size) "Data ready tag=0x%x len=%zd"
+scsi_disk_read_data_count(uint32_t sector_count) "Read sector_count=%d"
+scsi_disk_read_data_invalid(void) "Data transfer direction invalid"
+scsi_disk_write_complete_noio(uint32_t tag, size_t size) "Write complete tag=0x%x more=%zd"
+scsi_disk_write_data_invalid(void) "Data transfer direction invalid"
+scsi_disk_emulate_vpd_page_00(size_t xfer) "Inquiry EVPD[Supported pages] buffer size %zd"
+scsi_disk_emulate_vpd_page_80_not_supported(void) "Inquiry (EVPD[Serial number] not supported"
+scsi_disk_emulate_vpd_page_80(size_t xfer) "Inquiry EVPD[Serial number] buffer size %zd"
+scsi_disk_emulate_vpd_page_83(size_t xfer) "Inquiry EVPD[Device identification] buffer size %zd"
+scsi_disk_emulate_vpd_page_b0_not_supported(void) "Inquiry (EVPD[Block limits] not supported for CDROM"
+scsi_disk_emulate_mode_sense(int cmd, int page, size_t xfer, int control) "Mode Sense(%d) (page %d, xfer %zd, page_control %d)"
+scsi_disk_emulate_read_toc(int start_track, int format, int msf) "Read TOC (track %d format %d msf %d)"
+scsi_disk_emulate_read_data(int buflen) "Read buf_len=%d"
+scsi_disk_emulate_write_data(int buflen) "Write buf_len=%d"
+scsi_disk_emulate_command_SAI_16(void) "SAI READ CAPACITY(16)"
+scsi_disk_emulate_command_SAI_unsupported(void) "Unsupported Service Action In"
+scsi_disk_emulate_command_SEEK_10(uint64_t lba) "Seek(10) (sector %" PRId64 ")"
+scsi_disk_emulate_command_MODE_SELECT(size_t xfer) "Mode Select(6) (len %zd)"
+scsi_disk_emulate_command_MODE_SELECT_10(size_t xfer) "Mode Select(10) (len %zd)"
+scsi_disk_emulate_command_UNMAP(size_t xfer) "Unmap (len %zd)"
+scsi_disk_emulate_command_VERIFY(int bytchk) "Verify (bytchk %d)"
+scsi_disk_emulate_command_WRITE_SAME(int cmd, size_t xfer) "WRITE SAME %d (len %zd)"
+scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI command (0x%2.2x=%s)"
+scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)"
+scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)"
+scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s"
-- 
2.19.2

[Qemu-devel] [PATCH v2 2/2] scsi-generic: Convert from DPRINTF() macro to trace events

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Tested-by: Philippe Mathieu-Daudé <philmd@redhat.com>
---
 hw/scsi/scsi-generic.c | 56 ++++++++++++++++++++----------------------
 hw/scsi/trace-events   | 11 +++++++++
 2 files changed, 37 insertions(+), 30 deletions(-)

diff --git a/hw/scsi/scsi-generic.c b/hw/scsi/scsi-generic.c
index 7237b4162e..842f8e0893 100644
--- a/hw/scsi/scsi-generic.c
+++ b/hw/scsi/scsi-generic.c
@@ -18,21 +18,10 @@
 #include "hw/scsi/scsi.h"
 #include "hw/scsi/emulation.h"
 #include "sysemu/block-backend.h"
+#include "trace.h"
 
 #ifdef __linux__
 
-//#define DEBUG_SCSI
-
-#ifdef DEBUG_SCSI
-#define DPRINTF(fmt, ...) \
-do { printf("scsi-generic: " fmt , ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) do {} while(0)
-#endif
-
-#define BADF(fmt, ...) \
-do { fprintf(stderr, "scsi-generic: " fmt , ## __VA_ARGS__); } while (0)
-
 #include <scsi/sg.h>
 #include "scsi/constants.h"
 
@@ -98,8 +87,7 @@ static void scsi_command_complete_noio(SCSIGenericReq *r, int ret)
         }
     }
 
-    DPRINTF("Command complete 0x%p tag=0x%x status=%d\n",
-            r, r->req.tag, status);
+    trace_scsi_generic_command_complete_noio(r, r->req.tag, status);
 
     scsi_req_complete(&r->req, status);
 done:
@@ -259,7 +247,7 @@ static void scsi_read_complete(void * opaque, int ret)
     }
 
     len = r->io_header.dxfer_len - r->io_header.resid;
-    DPRINTF("Data ready tag=0x%x len=%d\n", r->req.tag, len);
+    trace_scsi_generic_read_complete(r->req.tag, len);
 
     r->len = -1;
 
@@ -335,7 +323,7 @@ static void scsi_read_data(SCSIRequest *req)
     SCSIDevice *s = r->req.dev;
     int ret;
 
-    DPRINTF("scsi_read_data tag=0x%x\n", req->tag);
+    trace_scsi_generic_read_data(req->tag);
 
     /* The request is used as the AIO opaque value, so add a ref.  */
     scsi_req_ref(&r->req);
@@ -356,7 +344,7 @@ static void scsi_write_complete(void * opaque, int ret)
     SCSIGenericReq *r = (SCSIGenericReq *)opaque;
     SCSIDevice *s = r->req.dev;
 
-    DPRINTF("scsi_write_complete() ret = %d\n", ret);
+    trace_scsi_generic_write_complete(ret);
 
     assert(r->req.aiocb != NULL);
     r->req.aiocb = NULL;
@@ -371,7 +359,7 @@ static void scsi_write_complete(void * opaque, int ret)
     if (r->req.cmd.buf[0] == MODE_SELECT && r->req.cmd.buf[4] == 12 &&
         s->type == TYPE_TAPE) {
         s->blocksize = (r->buf[9] << 16) | (r->buf[10] << 8) | r->buf[11];
-        DPRINTF("block size %d\n", s->blocksize);
+        trace_scsi_generic_write_complete_blocksize(s->blocksize);
     }
 
     scsi_command_complete_noio(r, ret);
@@ -388,7 +376,7 @@ static void scsi_write_data(SCSIRequest *req)
     SCSIDevice *s = r->req.dev;
     int ret;
 
-    DPRINTF("scsi_write_data tag=0x%x\n", req->tag);
+    trace_scsi_generic_write_data(req->tag);
     if (r->len == 0) {
         r->len = r->buflen;
         scsi_req_data(&r->req, r->len);
@@ -411,6 +399,21 @@ static uint8_t *scsi_get_buf(SCSIRequest *req)
     return r->buf;
 }
 
+static void scsi_generic_command_dump(uint8_t *cmd, int len)
+{
+    int i;
+    char *line_buffer, *p;
+
+    line_buffer = g_malloc(len * 5 + 1);
+
+    for (i = 0, p = line_buffer; i < len; i++) {
+        p += sprintf(p, " 0x%02x", cmd[i]);
+    }
+    trace_scsi_generic_send_command(line_buffer);
+
+    g_free(line_buffer);
+}
+
 /* Execute a scsi command.  Returns the length of the data expected by the
    command.  This will be Positive for data transfers from the device
    (eg. disk reads), negative for transfers to the device (eg. disk writes),
@@ -422,16 +425,9 @@ static int32_t scsi_send_command(SCSIRequest *req, uint8_t *cmd)
     SCSIDevice *s = r->req.dev;
     int ret;
 
-#ifdef DEBUG_SCSI
-    DPRINTF("Command: data=0x%02x", cmd[0]);
-    {
-        int i;
-        for (i = 1; i < r->req.cmd.len; i++) {
-            printf(" 0x%02x", cmd[i]);
-        }
-        printf("\n");
+    if (trace_event_get_state_backends(TRACE_SCSI_GENERIC_SEND_COMMAND)) {
+        scsi_generic_command_dump(cmd, r->req.cmd.len);
     }
-#endif
 
     if (r->req.cmd.xfer == 0) {
         g_free(r->buf);
@@ -693,7 +689,7 @@ static void scsi_generic_realize(SCSIDevice *s, Error **errp)
 
     /* define device state */
     s->type = scsiid.scsi_type;
-    DPRINTF("device type %d\n", s->type);
+    trace_scsi_generic_realize_type(s->type);
 
     switch (s->type) {
     case TYPE_TAPE:
@@ -716,7 +712,7 @@ static void scsi_generic_realize(SCSIDevice *s, Error **errp)
         break;
     }
 
-    DPRINTF("block size %d\n", s->blocksize);
+    trace_scsi_generic_realize_blocksize(s->blocksize);
 
     /* Only used by scsi-block, but initialize it nevertheless to be clean.  */
     s->default_scsi_version = -1;
diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index e9625f790c..3c2fd7f52f 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -320,3 +320,14 @@ scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI comma
 scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)"
 scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)"
 scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s"
+
+# hw/scsi/scsi-generic.c
+scsi_generic_command_complete_noio(void *req, uint32_t tag, int statuc) "Command complete %p tag=0x%x status=%d"
+scsi_generic_read_complete(uint32_t tag, int len) "Data ready tag=0x%x len=%d"
+scsi_generic_read_data(uint32_t tag) "scsi_read_data tag=0x%x"
+scsi_generic_write_complete(int ret) "scsi_write_complete() ret = %d"
+scsi_generic_write_complete_blocksize(int blocksize) "block size %d"
+scsi_generic_write_data(uint32_t tag) "scsi_write_data tag=0x%x"
+scsi_generic_send_command(const char *line) "Command: data=%s"
+scsi_generic_realize_type(int type) "device type %d"
+scsi_generic_realize_blocksize(int blocksize) "block size %d"
-- 
2.19.2