diff mbox

[5/5] spapr_vscsi: convert to trace framework instead of DPRINTF

Message ID 1473878907-10477-6-git-send-email-lvivier@redhat.com
State New
Headers show

Commit Message

Laurent Vivier Sept. 14, 2016, 6:48 p.m. UTC 
Signed-off-by: Laurent Vivier <lvivier@redhat.com>
---
 hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
 hw/scsi/trace-events  | 27 ++++++++++++++++
 2 files changed, 63 insertions(+), 53 deletions(-)

Comments

Thomas Huth Sept. 14, 2016, 7:56 p.m. UTC | #1 
On 14.09.2016 20:48, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
>  hw/scsi/trace-events  | 27 ++++++++++++++++
>  2 files changed, 63 insertions(+), 53 deletions(-)
> 
> diff --git a/hw/scsi/spapr_vscsi.c b/hw/scsi/spapr_vscsi.c
> index 8fbd50f..29fef90 100644
> --- a/hw/scsi/spapr_vscsi.c
> +++ b/hw/scsi/spapr_vscsi.c

While you're at it: There is a stray fprintf statement at the beginning
of vscsi_process_tsk_mgmt() which is rather a debug statement than
really something that should be printed always ... could you please turn
that into a trace event, too?

 Thanks,
  Thomas
Eric Blake Sept. 14, 2016, 8:09 p.m. UTC | #2 
On 09/14/2016 01:48 PM, Laurent Vivier wrote:
> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> ---
>  hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
>  hw/scsi/trace-events  | 27 ++++++++++++++++
>  2 files changed, 63 insertions(+), 53 deletions(-)
> 

> +++ b/hw/scsi/trace-events
> @@ -202,3 +202,30 @@ esp_pci_dma_abort(uint32_t val) "ABORT (%.8x)"
>  esp_pci_dma_start(uint32_t val) "START (%.8x)"
>  esp_pci_sbac_read(uint32_t reg) "sbac: 0x%8.8x"
>  esp_pci_sbac_write(uint32_t reg, uint32_t val) "sbac: 0x%8.8x -> 0x%8.8x"
> +
> +# hw/scsi/spapr_vscsi.c
> +
> +spapr_vscsi_send_rsp(uint8_t status, int32_t res_in, int32_t res_out) "status: 0x%x, res_in: %"PRId32", res_out: %"PRId32

Same as before.

> +spapr_vscsi_fetch_desc_no_data(void) "no data descriptor"
> +spapr_vscsi_fetch_desc_direct(void) "direct segment"
> +spapr_vscsi_fetch_desc_indirect(uint32_t qtag, unsigned desc, unsigned local_desc) "indirect segment local tag=0x%"PRIx32" desc#%u/%u"
> +spapr_vscsi_fetch_desc_out_of_range(unsigned desc, unsigned desc_offset) "#%u is ouf of range (%u bytes)"
> +spapr_vscsi_fetch_desc_dma_read_error(int rc) "spapr_vio_dma_read -> %d reading ext_desc"
> +spapr_vscsi_fetch_desc_indirect_seg_ext(uint32_t qtag, unsigned n, unsigned desc, uint64_t va, uint32_t len) "indirect segment ext. tag=0x%"PRIx32" desc#%u/%u { va=0x%"PRIx64" len=0x%"PRIx32" }"
> +spapr_vscsi_fetch_desc_out_of_desc(void) "Out of descriptors !"

Probably worth dropping the ' !' while touching this (first, English
doesn't want space before !; second, ! usually means you are shouting at
the user, and doesn't appear in many other traces as a result).
David Gibson Sept. 15, 2016, 12:09 a.m. UTC | #3 
On Wed, Sep 14, 2016 at 09:56:47PM +0200, Thomas Huth wrote:
> On 14.09.2016 20:48, Laurent Vivier wrote:
> > Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> > ---
> >  hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
> >  hw/scsi/trace-events  | 27 ++++++++++++++++
> >  2 files changed, 63 insertions(+), 53 deletions(-)
> > 
> > diff --git a/hw/scsi/spapr_vscsi.c b/hw/scsi/spapr_vscsi.c
> > index 8fbd50f..29fef90 100644
> > --- a/hw/scsi/spapr_vscsi.c
> > +++ b/hw/scsi/spapr_vscsi.c
> 
> While you're at it: There is a stray fprintf statement at the beginning
> of vscsi_process_tsk_mgmt() which is rather a debug statement than
> really something that should be printed always ... could you please turn
> that into a trace event, too?

That would be a good idea, but I'd prefer to see it as a follow up patch.
David Gibson Sept. 15, 2016, 12:10 a.m. UTC | #4 
On Wed, Sep 14, 2016 at 03:09:31PM -0500, Eric Blake wrote:
> On 09/14/2016 01:48 PM, Laurent Vivier wrote:
> > Signed-off-by: Laurent Vivier <lvivier@redhat.com>
> > ---
> >  hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
> >  hw/scsi/trace-events  | 27 ++++++++++++++++
> >  2 files changed, 63 insertions(+), 53 deletions(-)
> > 
> 
> > +++ b/hw/scsi/trace-events
> > @@ -202,3 +202,30 @@ esp_pci_dma_abort(uint32_t val) "ABORT (%.8x)"
> >  esp_pci_dma_start(uint32_t val) "START (%.8x)"
> >  esp_pci_sbac_read(uint32_t reg) "sbac: 0x%8.8x"
> >  esp_pci_sbac_write(uint32_t reg, uint32_t val) "sbac: 0x%8.8x -> 0x%8.8x"
> > +
> > +# hw/scsi/spapr_vscsi.c
> > +
> > +spapr_vscsi_send_rsp(uint8_t status, int32_t res_in, int32_t res_out) "status: 0x%x, res_in: %"PRId32", res_out: %"PRId32
> 
> Same as before.

I've removed these blank lines as I merged.

> > +spapr_vscsi_fetch_desc_no_data(void) "no data descriptor"
> > +spapr_vscsi_fetch_desc_direct(void) "direct segment"
> > +spapr_vscsi_fetch_desc_indirect(uint32_t qtag, unsigned desc, unsigned local_desc) "indirect segment local tag=0x%"PRIx32" desc#%u/%u"
> > +spapr_vscsi_fetch_desc_out_of_range(unsigned desc, unsigned desc_offset) "#%u is ouf of range (%u bytes)"
> > +spapr_vscsi_fetch_desc_dma_read_error(int rc) "spapr_vio_dma_read -> %d reading ext_desc"
> > +spapr_vscsi_fetch_desc_indirect_seg_ext(uint32_t qtag, unsigned n, unsigned desc, uint64_t va, uint32_t len) "indirect segment ext. tag=0x%"PRIx32" desc#%u/%u { va=0x%"PRIx64" len=0x%"PRIx32" }"
> > +spapr_vscsi_fetch_desc_out_of_desc(void) "Out of descriptors !"
> 
> Probably worth dropping the ' !' while touching this (first, English
> doesn't want space before !; second, ! usually means you are shouting at
> the user, and doesn't appear in many other traces as a result).

That's a good change, but I'd prefer to see it as a follow up patch.
Laurent Vivier Sept. 15, 2016, 7:37 a.m. UTC | #5 
On 14/09/2016 22:09, Eric Blake wrote:
> On 09/14/2016 01:48 PM, Laurent Vivier wrote:
>> Signed-off-by: Laurent Vivier <lvivier@redhat.com>
>> ---
>>  hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------
>>  hw/scsi/trace-events  | 27 ++++++++++++++++
>>  2 files changed, 63 insertions(+), 53 deletions(-)
>>
> 
>> +++ b/hw/scsi/trace-events
>> @@ -202,3 +202,30 @@ esp_pci_dma_abort(uint32_t val) "ABORT (%.8x)"
>>  esp_pci_dma_start(uint32_t val) "START (%.8x)"
>>  esp_pci_sbac_read(uint32_t reg) "sbac: 0x%8.8x"
>>  esp_pci_sbac_write(uint32_t reg, uint32_t val) "sbac: 0x%8.8x -> 0x%8.8x"
>> +
>> +# hw/scsi/spapr_vscsi.c
>> +
>> +spapr_vscsi_send_rsp(uint8_t status, int32_t res_in, int32_t res_out) "status: 0x%x, res_in: %"PRId32", res_out: %"PRId32
> 
> Same as before.
> 
>> +spapr_vscsi_fetch_desc_no_data(void) "no data descriptor"
>> +spapr_vscsi_fetch_desc_direct(void) "direct segment"
>> +spapr_vscsi_fetch_desc_indirect(uint32_t qtag, unsigned desc, unsigned local_desc) "indirect segment local tag=0x%"PRIx32" desc#%u/%u"
>> +spapr_vscsi_fetch_desc_out_of_range(unsigned desc, unsigned desc_offset) "#%u is ouf of range (%u bytes)"
>> +spapr_vscsi_fetch_desc_dma_read_error(int rc) "spapr_vio_dma_read -> %d reading ext_desc"
>> +spapr_vscsi_fetch_desc_indirect_seg_ext(uint32_t qtag, unsigned n, unsigned desc, uint64_t va, uint32_t len) "indirect segment ext. tag=0x%"PRIx32" desc#%u/%u { va=0x%"PRIx64" len=0x%"PRIx32" }"
>> +spapr_vscsi_fetch_desc_out_of_desc(void) "Out of descriptors !"
> 
> Probably worth dropping the ' !' while touching this (first, English
> doesn't want space before !; second, ! usually means you are shouting at

This is what happens when you let french people writing code...

Thank you for the review, Eric.

Laurent
diff mbox

Patch

diff --git a/hw/scsi/spapr_vscsi.c b/hw/scsi/spapr_vscsi.c
index 8fbd50f..29fef90 100644
--- a/hw/scsi/spapr_vscsi.c
+++ b/hw/scsi/spapr_vscsi.c
@@ -42,19 +42,10 @@ 
 #include "hw/ppc/spapr.h"
 #include "hw/ppc/spapr_vio.h"
 #include "viosrp.h"
+#include "trace.h"
 
 #include <libfdt.h>
 
-/*#define DEBUG_VSCSI*/
-
-#ifdef DEBUG_VSCSI
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#endif
-
 /*
  * Virtual SCSI device
  */
@@ -237,8 +228,7 @@  static int vscsi_send_rsp(VSCSIState *s, vscsi_req *req,
     int total_len = sizeof(iu->srp.rsp);
     uint8_t sol_not = iu->srp.cmd.sol_not;
 
-    DPRINTF("VSCSI: Sending resp status: 0x%x, "
-            "res_in: %d, res_out: %d\n", status, res_in, res_out);
+    trace_spapr_vscsi_send_rsp(status, res_in, res_out);
 
     memset(iu, 0, sizeof(struct srp_rsp));
     iu->srp.rsp.opcode = SRP_RSP;
@@ -298,13 +288,13 @@  static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
 
     switch (req->dma_fmt) {
     case SRP_NO_DATA_DESC: {
-        DPRINTF("VSCSI: no data descriptor\n");
+        trace_spapr_vscsi_fetch_desc_no_data();
         return 0;
     }
     case SRP_DATA_DESC_DIRECT: {
         memcpy(ret, cmd->add_data + req->cdb_offset, sizeof(*ret));
         assert(req->cur_desc_num == 0);
-        DPRINTF("VSCSI: direct segment\n");
+        trace_spapr_vscsi_fetch_desc_direct();
         break;
     }
     case SRP_DATA_DESC_INDIRECT: {
@@ -312,30 +302,29 @@  static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
                                        (cmd->add_data + req->cdb_offset);
         if (n < req->local_desc) {
             *ret = tmp->desc_list[n];
-            DPRINTF("VSCSI: indirect segment local tag=0x%x desc#%d/%d\n",
-                    req->qtag, n, req->local_desc);
-
+            trace_spapr_vscsi_fetch_desc_indirect(req->qtag, n,
+                                                  req->local_desc);
         } else if (n < req->total_desc) {
             int rc;
             struct srp_direct_buf tbl_desc = vscsi_swap_desc(tmp->table_desc);
             unsigned desc_offset = n * sizeof(struct srp_direct_buf);
 
             if (desc_offset >= tbl_desc.len) {
-                DPRINTF("VSCSI:   #%d is ouf of range (%d bytes)\n",
-                        n, desc_offset);
+                trace_spapr_vscsi_fetch_desc_out_of_range(n, desc_offset);
                 return -1;
             }
             rc = spapr_vio_dma_read(&s->vdev, tbl_desc.va + desc_offset,
                                     ret, sizeof(struct srp_direct_buf));
             if (rc) {
-                DPRINTF("VSCSI: spapr_vio_dma_read -> %d reading ext_desc\n",
-                        rc);
+                trace_spapr_vscsi_fetch_desc_dma_read_error(rc);
                 return -1;
             }
-            DPRINTF("VSCSI: indirect segment ext. tag=0x%x desc#%d/%d { va=%"PRIx64" len=%x }\n",
-                    req->qtag, n, req->total_desc, tbl_desc.va, tbl_desc.len);
+            trace_spapr_vscsi_fetch_desc_indirect_seg_ext(req->qtag, n,
+                                                          req->total_desc,
+                                                          tbl_desc.va,
+                                                          tbl_desc.len);
         } else {
-            DPRINTF("VSCSI:   Out of descriptors !\n");
+            trace_spapr_vscsi_fetch_desc_out_of_desc();
             return 0;
         }
         break;
@@ -347,15 +336,16 @@  static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
 
     *ret = vscsi_swap_desc(*ret);
     if (buf_offset > ret->len) {
-        DPRINTF("   offset=%x is out of a descriptor #%d boundary=%x\n",
-                buf_offset, req->cur_desc_num, ret->len);
+        trace_spapr_vscsi_fetch_desc_out_of_desc_boundary(buf_offset,
+                                                          req->cur_desc_num,
+                                                          ret->len);
         return -1;
     }
     ret->va += buf_offset;
     ret->len -= buf_offset;
 
-    DPRINTF("   cur=%d offs=%x ret { va=%"PRIx64" len=%x }\n",
-            req->cur_desc_num, req->cur_desc_offset, ret->va, ret->len);
+    trace_spapr_vscsi_fetch_desc_done(req->cur_desc_num, req->cur_desc_offset,
+                                      ret->va, ret->len);
 
     return ret->len ? 1 : 0;
 }
@@ -398,7 +388,7 @@  static int vscsi_srp_indirect_data(VSCSIState *s, vscsi_req *req,
     int rc = 0;
     uint32_t llen, total = 0;
 
-    DPRINTF("VSCSI: indirect segment 0x%x bytes\n", len);
+    trace_spapr_vscsi_srp_indirect_data(len);
 
     /* While we have data ... */
     while (len) {
@@ -417,11 +407,10 @@  static int vscsi_srp_indirect_data(VSCSIState *s, vscsi_req *req,
             rc = spapr_vio_dma_write(&s->vdev, md.va, buf, llen);
         }
         if (rc) {
-            DPRINTF("VSCSI: spapr_vio_dma_r/w(%d) -> %d\n", req->writing, rc);
+            trace_spapr_vscsi_srp_indirect_data_rw(req->writing, rc);
             break;
         }
-        DPRINTF("VSCSI:     data: %02x %02x %02x %02x...\n",
-                buf[0], buf[1], buf[2], buf[3]);
+        trace_spapr_vscsi_srp_indirect_data_buf(buf[0], buf[1], buf[2], buf[3]);
 
         len -= llen;
         buf += llen;
@@ -447,7 +436,7 @@  static int vscsi_srp_transfer_data(VSCSIState *s, vscsi_req *req,
 
     switch (req->dma_fmt) {
     case SRP_NO_DATA_DESC:
-        DPRINTF("VSCSI: no data desc transfer, skipping 0x%x bytes\n", len);
+        trace_spapr_vscsi_srp_transfer_data(len);
         break;
     case SRP_DATA_DESC_DIRECT:
         err = vscsi_srp_direct_data(s, req, buf, len);
@@ -527,8 +516,7 @@  static void vscsi_transfer_data(SCSIRequest *sreq, uint32_t len)
     uint8_t *buf;
     int rc = 0;
 
-    DPRINTF("VSCSI: SCSI xfer complete tag=0x%x len=0x%x, req=%p\n",
-            sreq->tag, len, req);
+    trace_spapr_vscsi_transfer_data(sreq->tag, len, req);
     if (req == NULL) {
         fprintf(stderr, "VSCSI: Can't find request for tag 0x%x\n", sreq->tag);
         return;
@@ -557,8 +545,7 @@  static void vscsi_command_complete(SCSIRequest *sreq, uint32_t status, size_t re
     vscsi_req *req = sreq->hba_private;
     int32_t res_in = 0, res_out = 0;
 
-    DPRINTF("VSCSI: SCSI cmd complete, tag=0x%x status=0x%x, req=%p\n",
-            sreq->tag, status, req);
+    trace_spapr_vscsi_command_complete(sreq->tag, status, req);
     if (req == NULL) {
         fprintf(stderr, "VSCSI: Can't find request for tag 0x%x\n", sreq->tag);
         return;
@@ -567,16 +554,14 @@  static void vscsi_command_complete(SCSIRequest *sreq, uint32_t status, size_t re
     if (status == CHECK_CONDITION) {
         req->senselen = scsi_req_get_sense(req->sreq, req->sense,
                                            sizeof(req->sense));
-        DPRINTF("VSCSI: Sense data, %d bytes:\n", req->senselen);
-        DPRINTF("       %02x  %02x  %02x  %02x  %02x  %02x  %02x  %02x\n",
+        trace_spapr_vscsi_command_complete_sense_data(req->senselen,
                 req->sense[0], req->sense[1], req->sense[2], req->sense[3],
-                req->sense[4], req->sense[5], req->sense[6], req->sense[7]);
-        DPRINTF("       %02x  %02x  %02x  %02x  %02x  %02x  %02x  %02x\n",
+                req->sense[4], req->sense[5], req->sense[6], req->sense[7],
                 req->sense[8], req->sense[9], req->sense[10], req->sense[11],
                 req->sense[12], req->sense[13], req->sense[14], req->sense[15]);
     }
 
-    DPRINTF("VSCSI: Command complete err=%d\n", status);
+    trace_spapr_vscsi_command_complete_status(status);
     if (status == 0) {
         /* We handle overflows, not underflows for normal commands,
          * but hopefully nobody cares
@@ -635,8 +620,8 @@  static void vscsi_save_request(QEMUFile *f, SCSIRequest *sreq)
 
     vmstate_save_state(f, &vmstate_spapr_vscsi_req, req, NULL);
 
-    DPRINTF("VSCSI: saving tag=%u, current desc#%d, offset=%x\n",
-            req->qtag, req->cur_desc_num, req->cur_desc_offset);
+    trace_spapr_vscsi_save_request(req->qtag, req->cur_desc_num,
+                                   req->cur_desc_offset);
 }
 
 static void *vscsi_load_request(QEMUFile *f, SCSIRequest *sreq)
@@ -660,8 +645,8 @@  static void *vscsi_load_request(QEMUFile *f, SCSIRequest *sreq)
 
     req->sreq = scsi_req_ref(sreq);
 
-    DPRINTF("VSCSI: restoring tag=%u, current desc#%d, offset=%x\n",
-            req->qtag, req->cur_desc_num, req->cur_desc_offset);
+    trace_spapr_vscsi_load_request(req->qtag, req->cur_desc_num,
+                                   req->cur_desc_offset);
 
     return req;
 }
@@ -672,7 +657,7 @@  static void vscsi_process_login(VSCSIState *s, vscsi_req *req)
     struct srp_login_rsp *rsp = &iu->srp.login_rsp;
     uint64_t tag = iu->srp.rsp.tag;
 
-    DPRINTF("VSCSI: Got login, sendin response !\n");
+    trace_spapr_vscsi__process_login();
 
     /* TODO handle case that requested size is wrong and
      * buffer format is wrong
@@ -795,8 +780,7 @@  static int vscsi_queue_cmd(VSCSIState *s, vscsi_req *req)
 
     sdev = vscsi_device_find(&s->bus, be64_to_cpu(srp->cmd.lun), &lun);
     if (!sdev) {
-        DPRINTF("VSCSI: Command for lun %08" PRIx64 " with no drive\n",
-                be64_to_cpu(srp->cmd.lun));
+        trace_spapr_vscsi_queue_cmd_no_drive(be64_to_cpu(srp->cmd.lun));
         if (srp->cmd.cdb[0] == INQUIRY) {
             vscsi_inquiry_no_target(s, req);
         } else {
@@ -808,9 +792,8 @@  static int vscsi_queue_cmd(VSCSIState *s, vscsi_req *req)
     req->sreq = scsi_req_new(sdev, req->qtag, lun, srp->cmd.cdb, req);
     n = scsi_req_enqueue(req->sreq);
 
-    DPRINTF("VSCSI: Queued command tag 0x%x CMD 0x%x=%s LUN %d ret: %d\n",
-            req->qtag, srp->cmd.cdb[0], scsi_command_name(srp->cmd.cdb[0]),
-            lun, n);
+    trace_spapr_vscsi_queue_cmd(req->qtag, srp->cmd.cdb[0],
+                                scsi_command_name(srp->cmd.cdb[0]), lun, n);
 
     if (n) {
         /* Transfer direction must be set before preprocessing the
@@ -1141,7 +1124,7 @@  static int vscsi_do_crq(struct VIOsPAPRDevice *dev, uint8_t *crq_data)
     crq.s.IU_length = be16_to_cpu(crq.s.IU_length);
     crq.s.IU_data_ptr = be64_to_cpu(crq.s.IU_data_ptr);
 
-    DPRINTF("VSCSI: do_crq %02x %02x ...\n", crq.raw[0], crq.raw[1]);
+    trace_spapr_vscsi_do_crq(crq.raw[0], crq.raw[1]);
 
     switch (crq.s.valid) {
     case 0xc0: /* Init command/response */
diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index ed64858..e3770b5 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -202,3 +202,30 @@  esp_pci_dma_abort(uint32_t val) "ABORT (%.8x)"
 esp_pci_dma_start(uint32_t val) "START (%.8x)"
 esp_pci_sbac_read(uint32_t reg) "sbac: 0x%8.8x"
 esp_pci_sbac_write(uint32_t reg, uint32_t val) "sbac: 0x%8.8x -> 0x%8.8x"
+
+# hw/scsi/spapr_vscsi.c
+
+spapr_vscsi_send_rsp(uint8_t status, int32_t res_in, int32_t res_out) "status: 0x%x, res_in: %"PRId32", res_out: %"PRId32
+spapr_vscsi_fetch_desc_no_data(void) "no data descriptor"
+spapr_vscsi_fetch_desc_direct(void) "direct segment"
+spapr_vscsi_fetch_desc_indirect(uint32_t qtag, unsigned desc, unsigned local_desc) "indirect segment local tag=0x%"PRIx32" desc#%u/%u"
+spapr_vscsi_fetch_desc_out_of_range(unsigned desc, unsigned desc_offset) "#%u is ouf of range (%u bytes)"
+spapr_vscsi_fetch_desc_dma_read_error(int rc) "spapr_vio_dma_read -> %d reading ext_desc"
+spapr_vscsi_fetch_desc_indirect_seg_ext(uint32_t qtag, unsigned n, unsigned desc, uint64_t va, uint32_t len) "indirect segment ext. tag=0x%"PRIx32" desc#%u/%u { va=0x%"PRIx64" len=0x%"PRIx32" }"
+spapr_vscsi_fetch_desc_out_of_desc(void) "Out of descriptors !"
+spapr_vscsi_fetch_desc_out_of_desc_boundary(unsigned offset, unsigned desc, uint32_t len) "   offset=0x%x is out of a descriptor #%u boundary=%"PRIx32
+spapr_vscsi_fetch_desc_done(unsigned desc_num, unsigned desc_offset, uint64_t va, uint32_t len) "   cur=%u offs=0x%x ret { va=0x%"PRIx64" len=0x%"PRIx32" }"
+spapr_vscsi_srp_indirect_data(uint32_t len) "indirect segment 0x%"PRIx32" bytes"
+spapr_vscsi_srp_indirect_data_rw(int writing, int rc) "spapr_vio_dma_r/w(%d) -> %d"
+spapr_vscsi_srp_indirect_data_buf(unsigned a, unsigned b, unsigned c, unsigned d) "     data: %02x %02x %02x %02x..."
+spapr_vscsi_srp_transfer_data(uint32_t len) "no data desc transfer, skipping 0x%"PRIx32" bytes"
+spapr_vscsi_transfer_data(uint32_t tag, uint32_t len, void *req) "SCSI xfer complete tag=0x%"PRIx32" len=0x%"PRIx32", req=%p"
+spapr_vscsi_command_complete(uint32_t tag, uint32_t status, void *req) "SCSI cmd complete, tag=0x%"PRIx32" status=0x%"PRIx32", req=%p"
+spapr_vscsi_command_complete_sense_data(uint32_t len, unsigned s0, unsigned s1, unsigned s2, unsigned s3, unsigned s4, unsigned s5, unsigned s6, unsigned s7, unsigned s8, unsigned s9, unsigned s10, unsigned s11, unsigned s12, unsigned s13, unsigned s14, unsigned s15) "Sense data, %d bytes: %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x"
+spapr_vscsi_command_complete_status(uint32_t status) "Command complete err=%"PRIu32
+spapr_vscsi_save_request(uint32_t qtag, unsigned desc, unsigned offset) "saving tag=%"PRIu32", current desc#%u, offset=0x%x"
+spapr_vscsi_load_request(uint32_t qtag, unsigned desc, unsigned offset) "restoring tag=%"PRIu32", current desc#%u, offset=0x%x"
+spapr_vscsi__process_login(void) "Got login, sending response !"
+spapr_vscsi_queue_cmd_no_drive(uint64_t lun) "Command for lun %08" PRIx64 " with no drive"
+spapr_vscsi_queue_cmd(uint32_t qtag, unsigned cdb, const char *cmd, int lun, int ret) "Queued command tag 0x%"PRIx32" CMD 0x%x=%s LUN %d ret: %d"
+spapr_vscsi_do_crq(unsigned c0, unsigned c1) "crq: %02x %02x ..."