Patchwork [2/2] add tracing of scsi requests

login
register
mail settings
Submitter Paolo Bonzini
Date April 15, 2011, 1:24 p.m.
Message ID <1302873840-17161-3-git-send-email-pbonzini@redhat.com>
Download mbox | patch
Permalink /patch/91373/
State New
Headers show

Comments

Paolo Bonzini - April 15, 2011, 1:24 p.m.
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
---
 hw/scsi-bus.c |   45 ++++++++++++++++++++++++++-------------------
 trace-events  |    6 ++++++
 2 files changed, 32 insertions(+), 19 deletions(-)
Stefan Hajnoczi - April 15, 2011, 2:15 p.m.
On Fri, Apr 15, 2011 at 2:24 PM, Paolo Bonzini <pbonzini@redhat.com> wrote:
> +disable scsi_req_parsed(int target, int lun, int tag, int cmd, const char *cmdname, int mode, int xfer, uint64_t lba) "target %d lun %d tag %d command %d (%s) dir %d length %d lba %"PRIu64""

Tracing strings isn't possible with all trace backends, so we should
avoid it.  It works fine with stderr but other trace backends may not
be in the same address space (they are unable to dereference pointers
to strings) or simply not have the ability to record variable-length
data.

For more info see the trace patches I posted earlier today.

Stefan
Paolo Bonzini - April 15, 2011, 2:22 p.m.
On 04/15/2011 04:15 PM, Stefan Hajnoczi wrote:
> On Fri, Apr 15, 2011 at 2:24 PM, Paolo Bonzini<pbonzini@redhat.com>  wrote:
>> +disable scsi_req_parsed(int target, int lun, int tag, int cmd, const char *cmdname, int mode, int xfer, uint64_t lba) "target %d lun %d tag %d command %d (%s) dir %d length %d lba %"PRIu64""
>
> Tracing strings isn't possible with all trace backends, so we should
> avoid it.  It works fine with stderr but other trace backends may not
> be in the same address space (they are unable to dereference pointers
> to strings) or simply not have the ability to record variable-length
> data.

Yeah, I saw them.  What happens with the other backends?  Do they crash 
or do they just record bogus data?  If the latter (like IIRC 
simpletrace), I'd really like to keep the string.  It is duplicating the 
cmd argument, so it is possible to work without it on non-stderr 
backends; with stderr OTOH the human-readable version is really useful 
before you have learnt the SCSI spec by heart. :)

Paolo
Stefan Hajnoczi - April 15, 2011, 2:32 p.m.
On Fri, Apr 15, 2011 at 3:22 PM, Paolo Bonzini <pbonzini@redhat.com> wrote:
> On 04/15/2011 04:15 PM, Stefan Hajnoczi wrote:
>>
>> On Fri, Apr 15, 2011 at 2:24 PM, Paolo Bonzini<pbonzini@redhat.com>
>>  wrote:
>>>
>>> +disable scsi_req_parsed(int target, int lun, int tag, int cmd, const
>>> char *cmdname, int mode, int xfer, uint64_t lba) "target %d lun %d tag %d
>>> command %d (%s) dir %d length %d lba %"PRIu64""
>>
>> Tracing strings isn't possible with all trace backends, so we should
>> avoid it.  It works fine with stderr but other trace backends may not
>> be in the same address space (they are unable to dereference pointers
>> to strings) or simply not have the ability to record variable-length
>> data.
>
> Yeah, I saw them.  What happens with the other backends?  Do they crash or
> do they just record bogus data?  If the latter (like IIRC simpletrace), I'd
> really like to keep the string.  It is duplicating the cmd argument, so it
> is possible to work without it on non-stderr backends; with stderr OTOH the
> human-readable version is really useful before you have learnt the SCSI spec
> by heart. :)

There should be no crashes during tracing but if a pretty-printing
tool uses the format string then there will be a crash :).  Right now
only stderr and ust use the format string.  I've forgotten whether or
not ust is happy with %s.

Once we allow %s how long will it take until people use it without
including the raw data?

Basically, yes, you can get away with it in some cases but it's a
slippery slope.  I'd rather forbid it now than end up with a confusing
or half-working mess later.

Stefan
Paolo Bonzini - April 15, 2011, 2:38 p.m.
On 04/15/2011 04:32 PM, Stefan Hajnoczi wrote:
> I've forgotten whether or not ust is happy with %s.

Ok, that's enough to convince me.

Paolo

Patch

diff --git a/hw/scsi-bus.c b/hw/scsi-bus.c
index ceeb4ec..6b306a7 100644
--- a/hw/scsi-bus.c
+++ b/hw/scsi-bus.c
@@ -4,6 +4,7 @@ 
 #include "scsi-defs.h"
 #include "qdev.h"
 #include "blockdev.h"
+#include "trace.h"
 
 static char *scsibus_get_fw_dev_path(DeviceState *dev);
 
@@ -141,6 +142,7 @@  SCSIRequest *scsi_req_alloc(size_t size, SCSIDevice *d, uint32_t tag, uint32_t l
     req->lun = lun;
     req->status = -1;
     req->enqueued = true;
+    trace_scsi_req_alloc(req->dev->id, req->lun, req->tag);
     QTAILQ_INSERT_TAIL(&d->requests, req, next);
     return req;
 }
@@ -159,6 +161,7 @@  SCSIRequest *scsi_req_find(SCSIDevice *d, uint32_t tag)
 
 static void scsi_req_dequeue(SCSIRequest *req)
 {
+    trace_scsi_req_dequeue(req->dev->id, req->lun, req->tag);
     if (req->enqueued) {
         QTAILQ_REMOVE(&req->dev->requests, req, next);
         req->enqueued = false;
@@ -195,6 +198,7 @@  static int scsi_req_length(SCSIRequest *req, uint8_t *cmd)
         req->cmd.len = 12;
         break;
     default:
+        trace_scsi_req_parse_bad(req->dev->id, req->lun, req->tag, cmd[0]);
         return -1;
     }
 
@@ -377,25 +381,7 @@  static uint64_t scsi_req_lba(SCSIRequest *req)
     return lba;
 }
 
-int scsi_req_parse(SCSIRequest *req, uint8_t *buf)
-{
-    int rc;
-
-    if (req->dev->type == TYPE_TAPE) {
-        rc = scsi_req_stream_length(req, buf);
-    } else {
-        rc = scsi_req_length(req, buf);
-    }
-    if (rc != 0)
-        return rc;
-
-    memcpy(req->cmd.buf, buf, req->cmd.len);
-    scsi_req_xfer_mode(req);
-    req->cmd.lba = scsi_req_lba(req);
-    return 0;
-}
-
-static const char *scsi_command_name(uint8_t cmd)
+static const char *__attribute__((const)) scsi_command_name(uint8_t cmd)
 {
     static const char *names[] = {
         [ TEST_UNIT_READY          ] = "TEST_UNIT_READY",
@@ -489,6 +475,28 @@  static const char *scsi_command_name(uint8_t cmd)
     return names[cmd];
 }
 
+int scsi_req_parse(SCSIRequest *req, uint8_t *buf)
+{
+    int rc;
+
+    if (req->dev->type == TYPE_TAPE) {
+        rc = scsi_req_stream_length(req, buf);
+    } else {
+        rc = scsi_req_length(req, buf);
+    }
+    if (rc != 0) {
+        return rc;
+    }
+
+    memcpy(req->cmd.buf, buf, req->cmd.len);
+    scsi_req_xfer_mode(req);
+    req->cmd.lba = scsi_req_lba(req);
+    trace_scsi_req_parsed(req->dev->id, req->lun, req->tag,
+                          buf[0], scsi_command_name(buf[0]), req->cmd.mode,
+                          req->cmd.xfer, req->cmd.lba);
+    return 0;
+}
+
 void scsi_req_print(SCSIRequest *req)
 {
     FILE *fp = stderr;
diff --git a/trace-events b/trace-events
index 703b745..51e2497 100644
--- a/trace-events
+++ b/trace-events
@@ -205,6 +205,12 @@  disable usb_set_config(int addr, int config, int ret) "dev %d, config %d, ret %d
 disable usb_clear_device_feature(int addr, int feature, int ret) "dev %d, feature %d, ret %d"
 disable usb_set_device_feature(int addr, int feature, int ret) "dev %d, feature %d, ret %d"
 
+# hw/scsi-bus.c
+disable scsi_req_alloc(int target, int lun, int tag) "target %d lun %d tag %d"
+disable scsi_req_dequeue(int target, int lun, int tag) "target %d lun %d tag %d"
+disable scsi_req_parsed(int target, int lun, int tag, int cmd, const char *cmdname, int mode, int xfer, uint64_t lba) "target %d lun %d tag %d command %d (%s) dir %d length %d lba %"PRIu64""
+disable scsi_req_parse_bad(int target, int lun, int tag, int cmd) "target %d lun %d tag %d command %d"
+
 # vl.c
 disable vm_state_notify(int running, int reason) "running %d reason %d"