[Qemu-devel] [PATCH v2 0/5] spapr: convert SPAPR devices to trace framework

[Qemu-devel] [PATCH v2 0/5] spapr: convert SPAPR devices to trace framework

[Laurent Vivier]

Define and use trace_spapr_XXX functions instead of
DPRINTF to trace some SPAPR devices: spapr_vio, spapr_drc, spapr_rtas,
spapr_llan, spapr_vscsi.

This allows to enable dynamically (instead of recompiling the source)
the traces for these devices. Messages are close as possible as
messages used by DPRINTF. Sometime, I've removed some text to
avoid redundancy between information given by the tracing function name
and the text displayed. I've also updated print format to use
the good conversion specifier ('u' instead of 'd' when the type is unsigned,
PRIx32 instead of 'x' when the type is uint32_t or int32_t, ...)

v2:
- fix spapr_vscsi with "ust" backend (limited number of arguments)
- Remove blank line after the comment line in trace-events files
- add Eric's R-b

David, you can take only patch 5/5, all the other patches are like they
are in your branch ppc-for-2.8.

Laurent Vivier (5):
  spapr_drc: convert to trace framework instead of DPRINTF
  spapr_rtas: convert to trace framework instead of DPRINTF
  spapr_vio: convert to trace framework instead of DPRINTF
  spapr_llan: convert to trace framework instead of DPRINTF
  spapr_vscsi: convert to trace framework instead of DPRINTF

 hw/net/spapr_llan.c   | 61 +++++++++++++++--------------------
 hw/net/trace-events   | 16 ++++++++++
 hw/ppc/spapr_drc.c    | 54 ++++++++++++-------------------
 hw/ppc/spapr_rtas.c   | 30 +++++-------------
 hw/ppc/spapr_vio.c    | 17 ++--------
 hw/ppc/trace-events   | 33 +++++++++++++++++++
 hw/scsi/spapr_vscsi.c | 88 +++++++++++++++++++++------------------------------
 hw/scsi/trace-events  | 27 ++++++++++++++++
 8 files changed, 168 insertions(+), 158 deletions(-)

-- 
2.5.5

[Qemu-devel] [PATCH v2 1/5] spapr_drc: convert to trace framework instead of DPRINTF

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
---
v2:
- Remove blank line after the comment line in trace-events file
- add Eric's R-b

 hw/ppc/spapr_drc.c  | 54 ++++++++++++++++++++---------------------------------
 hw/ppc/trace-events | 21 +++++++++++++++++++++
 2 files changed, 41 insertions(+), 34 deletions(-)

diff --git a/hw/ppc/spapr_drc.c b/hw/ppc/spapr_drc.c
index 4b1a943..6e54fd4 100644
--- a/hw/ppc/spapr_drc.c
+++ b/hw/ppc/spapr_drc.c
@@ -20,20 +20,7 @@
 #include "qapi/visitor.h"
 #include "qemu/error-report.h"
 #include "hw/ppc/spapr.h" /* for RTAS return codes */
-
-/* #define DEBUG_SPAPR_DRC */
-
-#ifdef DEBUG_SPAPR_DRC
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#define DPRINTFN(fmt, ...) \
-    do { DPRINTF(fmt, ## __VA_ARGS__); fprintf(stderr, "\n"); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#define DPRINTFN(fmt, ...) \
-    do { } while (0)
-#endif
+#include "trace.h"
 
 #define DRC_CONTAINER_PATH "/dr-connector"
 #define DRC_INDEX_TYPE_SHIFT 28
@@ -69,7 +56,7 @@ static uint32_t set_isolation_state(sPAPRDRConnector *drc,
 {
     sPAPRDRConnectorClass *drck = SPAPR_DR_CONNECTOR_GET_CLASS(drc);
 
-    DPRINTFN("drc: %x, set_isolation_state: %x", get_index(drc), state);
+    trace_spapr_drc_set_isolation_state(get_index(drc), state);
 
     if (state == SPAPR_DR_ISOLATION_STATE_UNISOLATED) {
         /* cannot unisolate a non-existant resource, and, or resources
@@ -94,11 +81,11 @@ static uint32_t set_isolation_state(sPAPRDRConnector *drc,
          */
         if (drc->awaiting_release) {
             if (drc->configured) {
-                DPRINTFN("finalizing device removal");
+                trace_spapr_drc_set_isolation_state_finalizing(get_index(drc));
                 drck->detach(drc, DEVICE(drc->dev), drc->detach_cb,
                              drc->detach_cb_opaque, NULL);
             } else {
-                DPRINTFN("deferring device removal on unconfigured device\n");
+                trace_spapr_drc_set_isolation_state_deferring(get_index(drc));
             }
         }
         drc->configured = false;
@@ -110,7 +97,7 @@ static uint32_t set_isolation_state(sPAPRDRConnector *drc,
 static uint32_t set_indicator_state(sPAPRDRConnector *drc,
                                     sPAPRDRIndicatorState state)
 {
-    DPRINTFN("drc: %x, set_indicator_state: %x", get_index(drc), state);
+    trace_spapr_drc_set_indicator_state(get_index(drc), state);
     drc->indicator_state = state;
     return RTAS_OUT_SUCCESS;
 }
@@ -120,7 +107,7 @@ static uint32_t set_allocation_state(sPAPRDRConnector *drc,
 {
     sPAPRDRConnectorClass *drck = SPAPR_DR_CONNECTOR_GET_CLASS(drc);
 
-    DPRINTFN("drc: %x, set_allocation_state: %x", get_index(drc), state);
+    trace_spapr_drc_set_allocation_state(get_index(drc), state);
 
     if (state == SPAPR_DR_ALLOCATION_STATE_USABLE) {
         /* if there's no resource/device associated with the DRC, there's
@@ -137,7 +124,7 @@ static uint32_t set_allocation_state(sPAPRDRConnector *drc,
         drc->allocation_state = state;
         if (drc->awaiting_release &&
             drc->allocation_state == SPAPR_DR_ALLOCATION_STATE_UNUSABLE) {
-            DPRINTFN("finalizing device removal");
+            trace_spapr_drc_set_allocation_state_finalizing(get_index(drc));
             drck->detach(drc, DEVICE(drc->dev), drc->detach_cb,
                          drc->detach_cb_opaque, NULL);
         } else if (drc->allocation_state == SPAPR_DR_ALLOCATION_STATE_USABLE) {
@@ -167,12 +154,11 @@ static const void *get_fdt(sPAPRDRConnector *drc, int *fdt_start_offset)
 
 static void set_configured(sPAPRDRConnector *drc)
 {
-    DPRINTFN("drc: %x, set_configured", get_index(drc));
+    trace_spapr_drc_set_configured(get_index(drc));
 
     if (drc->isolation_state != SPAPR_DR_ISOLATION_STATE_UNISOLATED) {
         /* guest should be not configuring an isolated device */
-        DPRINTFN("drc: %x, set_configured: skipping isolated device",
-                 get_index(drc));
+        trace_spapr_drc_set_configured_skipping(get_index(drc));
         return;
     }
     drc->configured = true;
@@ -222,7 +208,7 @@ static uint32_t entity_sense(sPAPRDRConnector *drc, sPAPRDREntitySense *state)
         }
     }
 
-    DPRINTFN("drc: %x, entity_sense: %x", get_index(drc), state);
+    trace_spapr_drc_entity_sense(get_index(drc), *state);
     return RTAS_OUT_SUCCESS;
 }
 
@@ -336,7 +322,7 @@ static void prop_get_fdt(Object *obj, Visitor *v, const char *name,
 static void attach(sPAPRDRConnector *drc, DeviceState *d, void *fdt,
                    int fdt_start_offset, bool coldplug, Error **errp)
 {
-    DPRINTFN("drc: %x, attach", get_index(drc));
+    trace_spapr_drc_attach(get_index(drc));
 
     if (drc->isolation_state != SPAPR_DR_ISOLATION_STATE_ISOLATED) {
         error_setg(errp, "an attached device is still awaiting release");
@@ -389,7 +375,7 @@ static void detach(sPAPRDRConnector *drc, DeviceState *d,
                    spapr_drc_detach_cb *detach_cb,
                    void *detach_cb_opaque, Error **errp)
 {
-    DPRINTFN("drc: %x, detach", get_index(drc));
+    trace_spapr_drc_detach(get_index(drc));
 
     drc->detach_cb = detach_cb;
     drc->detach_cb_opaque = detach_cb_opaque;
@@ -415,21 +401,21 @@ static void detach(sPAPRDRConnector *drc, DeviceState *d,
     }
 
     if (drc->isolation_state != SPAPR_DR_ISOLATION_STATE_ISOLATED) {
-        DPRINTFN("awaiting transition to isolated state before removal");
+        trace_spapr_drc_awaiting_isolated(get_index(drc));
         drc->awaiting_release = true;
         return;
     }
 
     if (drc->type != SPAPR_DR_CONNECTOR_TYPE_PCI &&
         drc->allocation_state != SPAPR_DR_ALLOCATION_STATE_UNUSABLE) {
-        DPRINTFN("awaiting transition to unusable state before removal");
+        trace_spapr_drc_awaiting_unusable(get_index(drc));
         drc->awaiting_release = true;
         return;
     }
 
     if (drc->awaiting_allocation) {
         drc->awaiting_release = true;
-        DPRINTFN("awaiting allocation to complete before removal");
+        trace_spapr_drc_awaiting_allocation(get_index(drc));
         return;
     }
 
@@ -460,7 +446,7 @@ static void reset(DeviceState *d)
     sPAPRDRConnectorClass *drck = SPAPR_DR_CONNECTOR_GET_CLASS(drc);
     sPAPRDREntitySense state;
 
-    DPRINTFN("drc reset: %x", drck->get_index(drc));
+    trace_spapr_drc_reset(drck->get_index(drc));
     /* immediately upon reset we can safely assume DRCs whose devices
      * are pending removal can be safely removed, and that they will
      * subsequently be left in an ISOLATED state. move the DRC to this
@@ -502,7 +488,7 @@ static void realize(DeviceState *d, Error **errp)
     gchar *child_name;
     Error *err = NULL;
 
-    DPRINTFN("drc realize: %x", drck->get_index(drc));
+    trace_spapr_drc_realize(drck->get_index(drc));
     /* NOTE: we do this as part of realize/unrealize due to the fact
      * that the guest will communicate with the DRC via RTAS calls
      * referencing the global DRC index. By unlinking the DRC
@@ -513,7 +499,7 @@ static void realize(DeviceState *d, Error **errp)
     root_container = container_get(object_get_root(), DRC_CONTAINER_PATH);
     snprintf(link_name, sizeof(link_name), "%x", drck->get_index(drc));
     child_name = object_get_canonical_path_component(OBJECT(drc));
-    DPRINTFN("drc child name: %s", child_name);
+    trace_spapr_drc_realize_child(drck->get_index(drc), child_name);
     object_property_add_alias(root_container, link_name,
                               drc->owner, child_name, &err);
     if (err) {
@@ -521,7 +507,7 @@ static void realize(DeviceState *d, Error **errp)
         object_unref(OBJECT(drc));
     }
     g_free(child_name);
-    DPRINTFN("drc realize complete");
+    trace_spapr_drc_realize_complete(drck->get_index(drc));
 }
 
 static void unrealize(DeviceState *d, Error **errp)
@@ -532,7 +518,7 @@ static void unrealize(DeviceState *d, Error **errp)
     char name[256];
     Error *err = NULL;
 
-    DPRINTFN("drc unrealize: %x", drck->get_index(drc));
+    trace_spapr_drc_unrealize(drck->get_index(drc));
     root_container = container_get(object_get_root(), DRC_CONTAINER_PATH);
     snprintf(name, sizeof(name), "%x", drck->get_index(drc));
     object_property_del(root_container, name, &err);
diff --git a/hw/ppc/trace-events b/hw/ppc/trace-events
index dfeab93..59caffd 100644
--- a/hw/ppc/trace-events
+++ b/hw/ppc/trace-events
@@ -35,6 +35,27 @@ spapr_iommu_ddw_create(uint64_t buid, uint32_t cfgaddr, uint64_t pg_size, uint64
 spapr_iommu_ddw_remove(uint32_t liobn) "liobn=%"PRIx32
 spapr_iommu_ddw_reset(uint64_t buid, uint32_t cfgaddr) "buid=%"PRIx64" addr=%"PRIx32
 
+# hw/ppc/spapr_drc.c
+spapr_drc_set_isolation_state(uint32_t index, int state) "drc: 0x%"PRIx32", state: %"PRIx32
+spapr_drc_set_isolation_state_finalizing(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_set_isolation_state_deferring(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_set_indicator_state(uint32_t index, int state) "drc: 0x%"PRIx32", state: 0x%x"
+spapr_drc_set_allocation_state(uint32_t index, int state) "drc: 0x%"PRIx32", state: 0x%x"
+spapr_drc_set_allocation_state_finalizing(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_set_configured(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_set_configured_skipping(uint32_t index) "drc: 0x%"PRIx32", isolated device"
+spapr_drc_entity_sense(uint32_t index, int state) "drc: 0x%"PRIx32", state: 0x%x"
+spapr_drc_attach(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_detach(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_awaiting_isolated(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_awaiting_unusable(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_awaiting_allocation(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_reset(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_realize(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_realize_child(uint32_t index, char *childname) "drc: 0x%"PRIx32", child name: %s"
+spapr_drc_realize_complete(uint32_t index) "drc: 0x%"PRIx32
+spapr_drc_unrealize(uint32_t index) "drc: 0x%"PRIx32
+
 # hw/ppc/ppc.c
 ppc_tb_adjust(uint64_t offs1, uint64_t offs2, int64_t diff, int64_t seconds) "adjusted from 0x%"PRIx64" to 0x%"PRIx64", diff %"PRId64" (%"PRId64"s)"
 
-- 
2.5.5

[Qemu-devel] [PATCH v2 2/5] spapr_rtas: convert to trace framework instead of DPRINTF

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
---
v2:
- Remove blank line after the comment line in trace-events file
- add Eric's R-b

 hw/ppc/spapr_rtas.c | 30 ++++++++----------------------
 hw/ppc/trace-events |  8 ++++++++
 2 files changed, 16 insertions(+), 22 deletions(-)

diff --git a/hw/ppc/spapr_rtas.c b/hw/ppc/spapr_rtas.c
index 27b5ad4..11cc3b9 100644
--- a/hw/ppc/spapr_rtas.c
+++ b/hw/ppc/spapr_rtas.c
@@ -44,16 +44,7 @@
 #include <libfdt.h>
 #include "hw/ppc/spapr_drc.h"
 #include "qemu/cutils.h"
-
-/* #define DEBUG_SPAPR */
-
-#ifdef DEBUG_SPAPR
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#endif
+#include "trace.h"
 
 static sPAPRConfigureConnectorState *spapr_ccs_find(sPAPRMachineState *spapr,
                                                     uint32_t drc_index)
@@ -435,8 +426,7 @@ static void rtas_set_indicator(PowerPCCPU *cpu, sPAPRMachineState *spapr,
     /* if this is a DR sensor we can assume sensor_index == drc_index */
     drc = spapr_dr_connector_by_index(sensor_index);
     if (!drc) {
-        DPRINTF("rtas_set_indicator: invalid sensor/DRC index: %xh\n",
-                sensor_index);
+        trace_spapr_rtas_set_indicator_invalid(sensor_index);
         ret = RTAS_OUT_PARAM_ERROR;
         goto out;
     }
@@ -475,8 +465,7 @@ out:
 
 out_unimplemented:
     /* currently only DR-related sensors are implemented */
-    DPRINTF("rtas_set_indicator: sensor/indicator not implemented: %d\n",
-            sensor_type);
+    trace_spapr_rtas_set_indicator_not_supported(sensor_index, sensor_type);
     rtas_st(rets, 0, RTAS_OUT_NOT_SUPPORTED);
 }
 
@@ -502,16 +491,15 @@ static void rtas_get_sensor_state(PowerPCCPU *cpu, sPAPRMachineState *spapr,
 
     if (sensor_type != RTAS_SENSOR_TYPE_ENTITY_SENSE) {
         /* currently only DR-related sensors are implemented */
-        DPRINTF("rtas_get_sensor_state: sensor/indicator not implemented: %d\n",
-                sensor_type);
+        trace_spapr_rtas_get_sensor_state_not_supported(sensor_index,
+                                                        sensor_type);
         ret = RTAS_OUT_NOT_SUPPORTED;
         goto out;
     }
 
     drc = spapr_dr_connector_by_index(sensor_index);
     if (!drc) {
-        DPRINTF("rtas_get_sensor_state: invalid sensor/DRC index: %xh\n",
-                sensor_index);
+        trace_spapr_rtas_get_sensor_state_invalid(sensor_index);
         ret = RTAS_OUT_PARAM_ERROR;
         goto out;
     }
@@ -568,8 +556,7 @@ static void rtas_ibm_configure_connector(PowerPCCPU *cpu,
     drc_index = rtas_ld(wa_addr, 0);
     drc = spapr_dr_connector_by_index(drc_index);
     if (!drc) {
-        DPRINTF("rtas_ibm_configure_connector: invalid DRC index: %xh\n",
-                drc_index);
+        trace_spapr_rtas_ibm_configure_connector_invalid(drc_index);
         rc = RTAS_OUT_PARAM_ERROR;
         goto out;
     }
@@ -577,8 +564,7 @@ static void rtas_ibm_configure_connector(PowerPCCPU *cpu,
     drck = SPAPR_DR_CONNECTOR_GET_CLASS(drc);
     fdt = drck->get_fdt(drc, NULL);
     if (!fdt) {
-        DPRINTF("rtas_ibm_configure_connector: Missing FDT for DRC index: %xh\n",
-                drc_index);
+        trace_spapr_rtas_ibm_configure_connector_missing_fdt(drc_index);
         rc = SPAPR_DR_CC_RESPONSE_NOT_CONFIGURABLE;
         goto out;
     }
diff --git a/hw/ppc/trace-events b/hw/ppc/trace-events
index 59caffd..34b5ec3 100644
--- a/hw/ppc/trace-events
+++ b/hw/ppc/trace-events
@@ -56,6 +56,14 @@ spapr_drc_realize_child(uint32_t index, char *childname) "drc: 0x%"PRIx32", chil
 spapr_drc_realize_complete(uint32_t index) "drc: 0x%"PRIx32
 spapr_drc_unrealize(uint32_t index) "drc: 0x%"PRIx32
 
+# hw/ppc/spapr_rtas.c
+spapr_rtas_set_indicator_invalid(uint32_t index) "sensor index: 0x%"PRIx32
+spapr_rtas_set_indicator_not_supported(uint32_t index, uint32_t type) "sensor index: 0x%"PRIx32", type: %"PRIu32
+spapr_rtas_get_sensor_state_not_supported(uint32_t index, uint32_t type) "sensor index: 0x%"PRIx32", type: %"PRIu32
+spapr_rtas_get_sensor_state_invalid(uint32_t index) "sensor index: 0x%"PRIx32
+spapr_rtas_ibm_configure_connector_invalid(uint32_t index) "DRC index: 0x%"PRIx32
+spapr_rtas_ibm_configure_connector_missing_fdt(uint32_t index) "DRC index: 0x%"PRIx32
+
 # hw/ppc/ppc.c
 ppc_tb_adjust(uint64_t offs1, uint64_t offs2, int64_t diff, int64_t seconds) "adjusted from 0x%"PRIx64" to 0x%"PRIx64", diff %"PRId64" (%"PRId64"s)"
 
-- 
2.5.5

[Qemu-devel] [PATCH v2 3/5] spapr_vio: convert to trace framework instead of DPRINTF

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
---
v2:
- Remove blank line after the comment line in trace-events file
- add Eric's R-b

 hw/ppc/spapr_vio.c  | 17 +++--------------
 hw/ppc/trace-events |  4 ++++
 2 files changed, 7 insertions(+), 14 deletions(-)

diff --git a/hw/ppc/spapr_vio.c b/hw/ppc/spapr_vio.c
index 497028f..d68dd35 100644
--- a/hw/ppc/spapr_vio.c
+++ b/hw/ppc/spapr_vio.c
@@ -36,19 +36,10 @@
 #include "hw/ppc/spapr.h"
 #include "hw/ppc/spapr_vio.h"
 #include "hw/ppc/xics.h"
+#include "trace.h"
 
 #include <libfdt.h>
 
-/* #define DEBUG_SPAPR */
-
-#ifdef DEBUG_SPAPR
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#endif
-
 static Property spapr_vio_props[] = {
     DEFINE_PROP_UINT32("irq", VIOsPAPRDevice, irq, 0), \
     DEFINE_PROP_END_OF_LIST(),
@@ -202,9 +193,7 @@ static target_ulong h_reg_crq(PowerPCCPU *cpu, sPAPRMachineState *spapr,
     dev->crq.qsize = queue_len;
     dev->crq.qnext = 0;
 
-    DPRINTF("CRQ for dev 0x" TARGET_FMT_lx " registered at 0x"
-            TARGET_FMT_lx "/0x" TARGET_FMT_lx "\n",
-            reg, queue_addr, queue_len);
+    trace_spapr_vio_h_reg_crq(reg, queue_addr, queue_len);
     return H_SUCCESS;
 }
 
@@ -214,7 +203,7 @@ static target_ulong free_crq(VIOsPAPRDevice *dev)
     dev->crq.qsize = 0;
     dev->crq.qnext = 0;
 
-    DPRINTF("CRQ for dev 0x%" PRIx32 " freed\n", dev->reg);
+    trace_spapr_vio_free_crq(dev->reg);
 
     return H_SUCCESS;
 }
diff --git a/hw/ppc/trace-events b/hw/ppc/trace-events
index 34b5ec3..2297ead 100644
--- a/hw/ppc/trace-events
+++ b/hw/ppc/trace-events
@@ -64,6 +64,10 @@ spapr_rtas_get_sensor_state_invalid(uint32_t index) "sensor index: 0x%"PRIx32
 spapr_rtas_ibm_configure_connector_invalid(uint32_t index) "DRC index: 0x%"PRIx32
 spapr_rtas_ibm_configure_connector_missing_fdt(uint32_t index) "DRC index: 0x%"PRIx32
 
+# hw/ppc/spapr_vio.c
+spapr_vio_h_reg_crq(uint64_t reg, uint64_t queue_addr, uint64_t queue_len) "CRQ for dev 0x%" PRIx64 " registered at 0x%" PRIx64 "/0x%" PRIx64
+spapr_vio_free_crq(uint32_t reg) "CRQ for dev 0x%" PRIx32 " freed"
+
 # hw/ppc/ppc.c
 ppc_tb_adjust(uint64_t offs1, uint64_t offs2, int64_t diff, int64_t seconds) "adjusted from 0x%"PRIx64" to 0x%"PRIx64", diff %"PRId64" (%"PRId64"s)"
 
-- 
2.5.5

[Qemu-devel] [PATCH v2 4/5] spapr_llan: convert to trace framework instead of DPRINTF

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
---
v2:
- Remove blank line after the comment line in trace-events file
- add Eric's R-b

 hw/net/spapr_llan.c | 61 ++++++++++++++++++++++-------------------------------
 hw/net/trace-events | 16 ++++++++++++++
 2 files changed, 41 insertions(+), 36 deletions(-)

diff --git a/hw/net/spapr_llan.c b/hw/net/spapr_llan.c
index 4bb95a5..01ecb02 100644
--- a/hw/net/spapr_llan.c
+++ b/hw/net/spapr_llan.c
@@ -34,20 +34,13 @@
 #include "hw/ppc/spapr.h"
 #include "hw/ppc/spapr_vio.h"
 #include "sysemu/sysemu.h"
+#include "trace.h"
 
 #include <libfdt.h>
 
 #define ETH_ALEN        6
 #define MAX_PACKET_SIZE 65536
 
-/*#define DEBUG*/
-
-#ifdef DEBUG
-#define DPRINTF(fmt...) do { fprintf(stderr, fmt); } while (0)
-#else
-#define DPRINTF(fmt...)
-#endif
-
 /* Compatibility flags for migration */
 #define SPAPRVLAN_FLAG_RX_BUF_POOLS_BIT  0
 #define SPAPRVLAN_FLAG_RX_BUF_POOLS      (1 << SPAPRVLAN_FLAG_RX_BUF_POOLS_BIT)
@@ -158,8 +151,10 @@ static vlan_bd_t spapr_vlan_get_rx_bd_from_pool(VIOsPAPRVLANDevice *dev,
         return 0;
     }
 
-    DPRINTF("Found buffer: pool=%d count=%d rxbufs=%d\n", pool,
-            dev->rx_pool[pool]->count, dev->rx_bufs);
+
+    trace_spapr_vlan_get_rx_bd_from_pool_found(pool,
+                                               dev->rx_pool[pool]->count,
+                                               dev->rx_bufs);
 
     /* Remove the buffer from the pool */
     dev->rx_pool[pool]->count--;
@@ -186,8 +181,8 @@ static vlan_bd_t spapr_vlan_get_rx_bd_from_page(VIOsPAPRVLANDevice *dev,
         }
 
         bd = vio_ldq(&dev->sdev, dev->buf_list + buf_ptr);
-        DPRINTF("use_buf_ptr=%d bd=0x%016llx\n",
-                buf_ptr, (unsigned long long)bd);
+
+        trace_spapr_vlan_get_rx_bd_from_page(buf_ptr, (uint64_t)bd);
     } while ((!(bd & VLAN_BD_VALID) || VLAN_BD_LEN(bd) < size + 8)
              && buf_ptr != dev->use_buf_ptr);
 
@@ -200,7 +195,7 @@ static vlan_bd_t spapr_vlan_get_rx_bd_from_page(VIOsPAPRVLANDevice *dev,
     dev->use_buf_ptr = buf_ptr;
     vio_stq(&dev->sdev, dev->buf_list + dev->use_buf_ptr, 0);
 
-    DPRINTF("Found buffer: ptr=%d rxbufs=%d\n", dev->use_buf_ptr, dev->rx_bufs);
+    trace_spapr_vlan_get_rx_bd_from_page_found(dev->use_buf_ptr, dev->rx_bufs);
 
     return bd;
 }
@@ -215,8 +210,7 @@ static ssize_t spapr_vlan_receive(NetClientState *nc, const uint8_t *buf,
     uint64_t handle;
     uint8_t control;
 
-    DPRINTF("spapr_vlan_receive() [%s] rx_bufs=%d\n", sdev->qdev.id,
-            dev->rx_bufs);
+    trace_spapr_vlan_receive(sdev->qdev.id, dev->rx_bufs);
 
     if (!dev->isopen) {
         return -1;
@@ -244,7 +238,7 @@ static ssize_t spapr_vlan_receive(NetClientState *nc, const uint8_t *buf,
         return -1;
     }
 
-    DPRINTF("spapr_vlan_receive: DMA write completed\n");
+    trace_spapr_vlan_receive_dma_completed();
 
     /* Update the receive queue */
     control = VLAN_RXQC_TOGGLE | VLAN_RXQC_VALID;
@@ -258,12 +252,11 @@ static ssize_t spapr_vlan_receive(NetClientState *nc, const uint8_t *buf,
     vio_sth(sdev, VLAN_BD_ADDR(rxq_bd) + dev->rxq_ptr + 2, 8);
     vio_stb(sdev, VLAN_BD_ADDR(rxq_bd) + dev->rxq_ptr, control);
 
-    DPRINTF("wrote rxq entry (ptr=0x%llx): 0x%016llx 0x%016llx\n",
-            (unsigned long long)dev->rxq_ptr,
-            (unsigned long long)vio_ldq(sdev, VLAN_BD_ADDR(rxq_bd) +
-                                        dev->rxq_ptr),
-            (unsigned long long)vio_ldq(sdev, VLAN_BD_ADDR(rxq_bd) +
-                                        dev->rxq_ptr + 8));
+    trace_spapr_vlan_receive_wrote(dev->rxq_ptr,
+                                   vio_ldq(sdev, VLAN_BD_ADDR(rxq_bd) +
+                                                 dev->rxq_ptr),
+                                   vio_ldq(sdev, VLAN_BD_ADDR(rxq_bd) +
+                                                 dev->rxq_ptr + 8));
 
     dev->rxq_ptr += 16;
     if (dev->rxq_ptr >= VLAN_BD_LEN(rxq_bd)) {
@@ -580,8 +573,8 @@ static target_long spapr_vlan_add_rxbuf_to_pool(VIOsPAPRVLANDevice *dev,
                 qsort(dev->rx_pool, RX_MAX_POOLS, sizeof(dev->rx_pool[0]),
                       rx_pool_size_compare);
                 pool = spapr_vlan_get_rx_pool_id(dev, size);
-                DPRINTF("created RX pool %d for size %lld\n", pool,
-                        VLAN_BD_LEN(buf));
+                trace_spapr_vlan_add_rxbuf_to_pool_create(pool,
+                                                          VLAN_BD_LEN(buf));
                 break;
             }
         }
@@ -591,8 +584,8 @@ static target_long spapr_vlan_add_rxbuf_to_pool(VIOsPAPRVLANDevice *dev,
         return H_RESOURCE;
     }
 
-    DPRINTF("h_add_llan_buf():  Add buf using pool %i (size %lli, count=%i)\n",
-            pool, VLAN_BD_LEN(buf), dev->rx_pool[pool]->count);
+    trace_spapr_vlan_add_rxbuf_to_pool(pool, VLAN_BD_LEN(buf),
+                                       dev->rx_pool[pool]->count);
 
     dev->rx_pool[pool]->bds[dev->rx_pool[pool]->count++] = buf;
 
@@ -623,8 +616,7 @@ static target_long spapr_vlan_add_rxbuf_to_page(VIOsPAPRVLANDevice *dev,
 
     vio_stq(&dev->sdev, dev->buf_list + dev->add_buf_ptr, buf);
 
-    DPRINTF("h_add_llan_buf():  Added buf  ptr=%d  rx_bufs=%d bd=0x%016llx\n",
-            dev->add_buf_ptr, dev->rx_bufs, (unsigned long long)buf);
+    trace_spapr_vlan_add_rxbuf_to_page(dev->add_buf_ptr, dev->rx_bufs, buf);
 
     return 0;
 }
@@ -640,8 +632,7 @@ static target_ulong h_add_logical_lan_buffer(PowerPCCPU *cpu,
     VIOsPAPRVLANDevice *dev = VIO_SPAPR_VLAN_DEVICE(sdev);
     target_long ret;
 
-    DPRINTF("H_ADD_LOGICAL_LAN_BUFFER(0x" TARGET_FMT_lx
-            ", 0x" TARGET_FMT_lx ")\n", reg, buf);
+    trace_spapr_vlan_h_add_logical_lan_buffer(reg, buf);
 
     if (!sdev) {
         hcall_dprintf("Bad device\n");
@@ -694,14 +685,13 @@ static target_ulong h_send_logical_lan(PowerPCCPU *cpu,
     int i, nbufs;
     int ret;
 
-    DPRINTF("H_SEND_LOGICAL_LAN(0x" TARGET_FMT_lx ", <bufs>, 0x"
-            TARGET_FMT_lx ")\n", reg, continue_token);
+    trace_spapr_vlan_h_send_logical_lan(reg, continue_token);
 
     if (!sdev) {
         return H_PARAMETER;
     }
 
-    DPRINTF("rxbufs = %d\n", dev->rx_bufs);
+    trace_spapr_vlan_h_send_logical_lan_rxbufs(dev->rx_bufs);
 
     if (!dev->isopen) {
         return H_DROPPED;
@@ -713,7 +703,7 @@ static target_ulong h_send_logical_lan(PowerPCCPU *cpu,
 
     total_len = 0;
     for (i = 0; i < 6; i++) {
-        DPRINTF("   buf desc: 0x" TARGET_FMT_lx "\n", bufs[i]);
+        trace_spapr_vlan_h_send_logical_lan_buf_desc(bufs[i]);
         if (!(bufs[i] & VLAN_BD_VALID)) {
             break;
         }
@@ -721,8 +711,7 @@ static target_ulong h_send_logical_lan(PowerPCCPU *cpu,
     }
 
     nbufs = i;
-    DPRINTF("h_send_logical_lan() %d buffers, total length 0x%x\n",
-            nbufs, total_len);
+    trace_spapr_vlan_h_send_logical_lan_total(nbufs, total_len);
 
     if (total_len == 0) {
         return H_SUCCESS;
diff --git a/hw/net/trace-events b/hw/net/trace-events
index 8d38d77..47ab14a 100644
--- a/hw/net/trace-events
+++ b/hw/net/trace-events
@@ -270,3 +270,19 @@ e1000e_cfg_support_virtio(bool support) "Virtio header supported: %d"
 
 e1000e_vm_state_running(void) "VM state is running"
 e1000e_vm_state_stopped(void) "VM state is stopped"
+
+# hw/net/spapr_llan.c
+spapr_vlan_get_rx_bd_from_pool_found(int pool, int32_t count, uint32_t rx_bufs) "pool=%d count=%"PRId32" rxbufs=%"PRIu32
+spapr_vlan_get_rx_bd_from_page(int buf_ptr, uint64_t bd) "use_buf_ptr=%d bd=0x%016"PRIx64
+spapr_vlan_get_rx_bd_from_page_found(uint32_t use_buf_ptr, uint32_t rx_bufs) "ptr=%"PRIu32" rxbufs=%"PRIu32
+spapr_vlan_receive(const char *id, uint32_t rx_bufs) "[%s] rx_bufs=%"PRIu32
+spapr_vlan_receive_dma_completed(void) "DMA write completed"
+spapr_vlan_receive_wrote(uint64_t ptr, uint64_t hi, uint64_t lo) "rxq entry (ptr=0x%"PRIx64"): 0x%016"PRIx64" 0x%016"PRIx64
+spapr_vlan_add_rxbuf_to_pool_create(int pool, uint64_t len) "created RX pool %d for size %"PRIu64
+spapr_vlan_add_rxbuf_to_pool(int pool, uint64_t len, int32_t count) "add buf using pool %d (size %"PRIu64", count=%"PRId32")"
+spapr_vlan_add_rxbuf_to_page(uint32_t ptr, uint32_t rx_bufs, uint64_t bd) "added buf ptr=%"PRIu32"  rx_bufs=%"PRIu32" bd=0x%016"PRIx64
+spapr_vlan_h_add_logical_lan_buffer(uint64_t reg, uint64_t buf) "H_ADD_LOGICAL_LAN_BUFFER(0x%"PRIx64", 0x%"PRIx64")"
+spapr_vlan_h_send_logical_lan(uint64_t reg, uint64_t continue_token) "H_SEND_LOGICAL_LAN(0x%"PRIx64", <bufs>, 0x%"PRIx64")"
+spapr_vlan_h_send_logical_lan_rxbufs(uint32_t rx_bufs) "rxbufs = %"PRIu32
+spapr_vlan_h_send_logical_lan_buf_desc(uint64_t buf) "   buf desc: 0x%"PRIx64
+spapr_vlan_h_send_logical_lan_total(int nbufs, unsigned total_len) "%d buffers, total length 0x%x"
-- 
2.5.5

[Qemu-devel] [PATCH v2 5/5] spapr_vscsi: convert to trace framework instead of DPRINTF

[Laurent Vivier]

Signed-off-by: Laurent Vivier <lvivier@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
---
v2:
- fix spapr_vscsi with "ust" backend (limited number of arguments)
- Remove blank line after the comment line in trace-events file
- add Eric's R-b

 hw/scsi/spapr_vscsi.c | 88 +++++++++++++++++++++------------------------------
 hw/scsi/trace-events  | 27 ++++++++++++++++
 2 files changed, 63 insertions(+), 52 deletions(-)

diff --git a/hw/scsi/spapr_vscsi.c b/hw/scsi/spapr_vscsi.c
index 8fbd50f..d8a2296 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,15 @@ 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_data1(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",
+        trace_spapr_vscsi_command_complete_sense_data2(
                 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 +621,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 +646,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 +658,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 +781,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 +793,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 +1125,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..d1995b8 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_data1(uint32_t len, unsigned s0, unsigned s1, unsigned s2, unsigned s3, unsigned s4, unsigned s5, unsigned s6, unsigned s7) "Sense data, %d bytes: %02x %02x %02x %02x %02x %02x %02x %02x"
+spapr_vscsi_command_complete_sense_data2(unsigned s8, unsigned s9, unsigned s10, unsigned s11, unsigned s12, unsigned s13, unsigned s14, unsigned s15)         "                      %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 ..."
-- 
2.5.5

Re: [Qemu-devel] [PATCH v2 0/5] spapr: convert SPAPR devices to trace framework

[David Gibson]

[-- Attachment #1: Type: text/plain, Size: 1215 bytes --]

On Fri, Sep 16, 2016 at 02:39:06PM +0200, Laurent Vivier wrote:
> Define and use trace_spapr_XXX functions instead of
> DPRINTF to trace some SPAPR devices: spapr_vio, spapr_drc, spapr_rtas,
> spapr_llan, spapr_vscsi.
> 
> This allows to enable dynamically (instead of recompiling the source)
> the traces for these devices. Messages are close as possible as
> messages used by DPRINTF. Sometime, I've removed some text to
> avoid redundancy between information given by the tracing function name
> and the text displayed. I've also updated print format to use
> the good conversion specifier ('u' instead of 'd' when the type is unsigned,
> PRIx32 instead of 'x' when the type is uint32_t or int32_t, ...)
> 
> v2:
> - fix spapr_vscsi with "ust" backend (limited number of arguments)
> - Remove blank line after the comment line in trace-events files
> - add Eric's R-b
> 
> David, you can take only patch 5/5, all the other patches are like they
> are in your branch ppc-for-2.8.

Done, thanks.

-- 
David Gibson			| I'll have my music baroque, and my code
david AT gibson.dropbear.id.au	| minimalist, thank you.  NOT _the_ _other_
				| _way_ _around_!
http://www.ozlabs.org/~dgibson

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 819 bytes --]