some virtio-scsi tracing
cover some virtio-scsi tracing
Recently we had to track down a (remote) problem with virtio-scsi tape passthrough. Paolo asked me if I could turn my ad-hoc debug printf()s into trace events.
I tested the series in the following way:
- enabled the two "processing hungry" events in "trace-events",
- built & installed qemu,
- using libvirt, started a guest with a passthru USB flash drive,
- logged in to the guest,
- on the host, enabled all virtio_scsi_* events using "virsh qemu-monitor-command",
- in the guest:
- mounted the disk,
- listed the directory tree,
- unmounted the disk,
- on the host, physically disconnected the flash drive.
I'm attaching the trace output (stderr backend, saved by libvirt); you should be able to pair segments of the file with the above actions.
Laszlo Ersek (2):
qemu_hexstr(): hexdump a small buffer to a string, for in-line
printing
add some virtio-scsi trace events
include/qemu-common.h | 11 +++++++ hw/scsi/virtio-scsi.c | 76 +++++++++++++++++++++++++++++++++++++++++++++++-- util/hexdump.c | 20 +++++++++++++ trace-events | 19 ++++++++++++ 4 files changed, 123 insertions(+), 3 deletions(-)
PATCH 1/2 qemu_hexstr(): hexdump a small buffer to a string, for in-line printing
This function should primarily serve tracing needs.
--- include/qemu-common.h | 11 +++++++++++ util/hexdump.c | 20 ++++++++++++++++++++ 2 files changed, 31 insertions(+), 0 deletions(-)
include/qemu-common.h +11 -0
@@ -433,6 +433,17 @@ int mod_utf8_codepoint(const char *s, size_t n, char **end);void qemu_hexdump (const char *buf,FILE *fp,const char *prefix,size_t size); +/* +* Hexdump @size bytes from @buf to a dynamically allocated string. +* If @size is NULL, then @buf can be a NULL pointer, and an empty string will +* be formatted. +* If @str_len is non-NULL, then the length of the output string (excluding the +* terminating NUL) will be stored in *@str_len. +* The output is meant to be printed on a single line, hence it contains no +* newlines, and @size should be reasonable. +*/ +char *qemu_hexstr (const void *buf,size_t size,size_t *str_len); +/* vector definitions */ #ifdef __ALTIVEC__#include <altivec.h>
util/hexdump.c +20 -0
@@ -35,3 +35,23 @@ void qemu_hexdump(const char *buf, FILE *fp, const char *prefix, size_t size)fprintf (fp,"\n" ); } } + +char *qemu_hexstr (const void *buf,size_t size,size_t *str_len) +{ +size_t str_size, i; +char *ret, *output; + + str_size = size *3 + (size ==0 ); + ret =g_malloc (str_size); + output = ret; + +for (i =0 ; i < size; ++i) { + output +=sprintf (output,"%s%02x" , (i ==0 ) ?"" :" " , + ((uint8_t *)buf)[i]); + } + *output ='\0' ; +if (str_len !=NULL ) { + *str_len = str_size -1 ; + } +return ret; +}
Signature · 1 line
1.7.1
PATCH 2/2 add some virtio-scsi trace events
In reply to Laszlo ErsekThe events that log a hexdump of the cdb and the sense buffer are disabled by default, because they require more processing than a simple trace_XXX() function call.
--- hw/scsi/virtio-scsi.c | 76 +++++++++++++++++++++++++++++++++++++++++++++++-- trace-events | 19 ++++++++++++ 2 files changed, 92 insertions(+), 3 deletions(-)
hw/scsi/virtio-scsi.c +73 -3
@@ -15,6 +15,7 @@#include "hw/virtio/virtio-scsi.h" #include "qemu/error-report.h" +#include "trace.h" #include <hw/scsi/scsi.h> #include <block/scsi.h> #include <hw/virtio/virtio-bus.h>
@@ -61,6 +62,8 @@ static void virtio_scsi_complete_req(VirtIOSCSIReq *req)VirtIOSCSI *s = req->dev;VirtQueue *vq = req->vq;VirtIODevice *vdev =VIRTIO_DEVICE (s); + +trace_virtio_scsi_complete_req_enter (req);virtqueue_push (vq, &req->elem, req->qsgl.size + req->elem.in_sg[0 ].iov_len);qemu_sglist_destroy (&req->qsgl);if (req->sreq) {
@@ -69,6 +72,7 @@ static void virtio_scsi_complete_req(VirtIOSCSIReq *req) }g_free (req);virtio_notify (vdev, vq); +trace_virtio_scsi_complete_req_exit (req); }static void virtio_scsi_bad_req (void )
@@ -121,6 +125,7 @@ static VirtIOSCSIReq *virtio_scsi_pop_req(VirtIOSCSI *s, VirtQueue *vq) }virtio_scsi_parse_req (s, vq, req); +trace_virtio_scsi_pop_req (req);return req; }
@@ -271,6 +276,7 @@ static void virtio_scsi_handle_ctrl(VirtIODevice *vdev, VirtQueue *vq)VirtIOSCSI *s = (VirtIOSCSI *)vdev;VirtIOSCSIReq *req; +trace_virtio_scsi_handle_ctrl_enter (vdev, vq);while ((req =virtio_scsi_pop_req (s, vq))) {int out_size, in_size;if (req->elem.out_num <1 || req->elem.in_num <1 ) {
@@ -298,14 +304,38 @@ static void virtio_scsi_handle_ctrl(VirtIODevice *vdev, VirtQueue *vq) }virtio_scsi_complete_req (req); } +trace_virtio_scsi_handle_ctrl_exit (vdev, vq); } +#if TRACE_VIRTIO_SCSI_DUMP_CMD_RESP_ENABLED +static void dump_cmd_resp (const VirtIOSCSIReq *req) +{ +const VirtIOSCSICmdResp *cr; +uint32_t sense_len; +char *sense_hex; + +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_RESP )) { +return ; + } + cr = req->resp.cmd; + sense_len = (cr->response ==VIRTIO_SCSI_S_OK && cr->status !=GOOD ) ? +tswap32 (cr->sense_len) :0 ; + sense_hex =qemu_hexstr (cr->sense, sense_len,NULL ); +trace_virtio_scsi_dump_cmd_resp ((void *)req, sense_len,tswap32 (cr->resid), + cr->status, cr->response, sense_hex); +g_free (sense_hex); +} +#else +static inline void dump_cmd_resp (const VirtIOSCSIReq *req) {} +#endif +static void virtio_scsi_command_complete (SCSIRequest *r,uint32_t status,size_t resid) {VirtIOSCSIReq *req = r->hba_private; -uint32_t sense_len; +uint32_t sense_len =0 ; +trace_virtio_scsi_command_complete_enter (req, status, resid); req->resp.cmd->response =VIRTIO_SCSI_S_OK ; req->resp.cmd->status = status;if (req->resp.cmd->status ==GOOD ) {
@@ -316,7 +346,9 @@ static void virtio_scsi_command_complete(SCSIRequest *r, uint32_t status, VIRTIO_SCSI_SENSE_SIZE); req->resp.cmd->sense_len =tswap32 (sense_len); } +dump_cmd_resp (req);virtio_scsi_complete_req (req); +trace_virtio_scsi_command_complete_exit (req, status, resid, sense_len); }static QEMUSGList *virtio_scsi_get_sg_list (SCSIRequest *r)
@@ -329,24 +361,51 @@ static QEMUSGList *virtio_scsi_get_sg_list(SCSIRequest *r)static void virtio_scsi_request_cancelled (SCSIRequest *r) {VirtIOSCSIReq *req = r->hba_private; +uint8_t resp =0 ; +trace_virtio_scsi_request_cancelled_enter (req);if (!req) { -return ; + goto out; }if (req->dev->resetting) { req->resp.cmd->response =VIRTIO_SCSI_S_RESET ; }else { req->resp.cmd->response =VIRTIO_SCSI_S_ABORTED ; } + resp = req->resp.cmd->response; +dump_cmd_resp (req);virtio_scsi_complete_req (req); +out: +trace_virtio_scsi_request_cancelled_exit (req, resp); }static void virtio_scsi_fail_cmd_req (VirtIOSCSIReq *req) { req->resp.cmd->response =VIRTIO_SCSI_S_FAILURE ; +dump_cmd_resp (req);virtio_scsi_complete_req (req); } +#if TRACE_VIRTIO_SCSI_DUMP_CMD_REQ_ENABLED +static void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) +{ +const VirtIOSCSICmdReq *cr; +char *cdb_hex; + +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_REQ )) { +return ; + } + cr = req->req.cmd; + cdb_hex =qemu_hexstr (cr->cdb, cdb_size,NULL ); +trace_virtio_scsi_dump_cmd_req ((void *)req, cr->tag, +virtio_scsi_get_lun ((uint8_t *)cr->lun), + cdb_hex); +g_free (cdb_hex); +} +#else +static inline void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) {} +#endif +static void virtio_scsi_handle_cmd (VirtIODevice *vdev,VirtQueue *vq) {/* use non-QOM casts in the data path */
@@ -356,6 +415,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)VirtIOSCSIReq *req;int n; +trace_virtio_scsi_handle_cmd_enter (vdev, vq);while ((req =virtio_scsi_pop_req (s, vq))) {SCSIDevice *d;int out_size, in_size;
@@ -378,9 +438,11 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq) d =virtio_scsi_device_find (s, req->req.cmd->lun);if (!d) { req->resp.cmd->response =VIRTIO_SCSI_S_BAD_TARGET ; +dump_cmd_resp (req);virtio_scsi_complete_req (req);continue ; } +dump_cmd_req (req, vs->cdb_size); req->sreq =scsi_req_new (d, req->req.cmd->tag,virtio_scsi_get_lun (req->req.cmd->lun), req->req.cmd->cdb, req);
@@ -392,6 +454,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)if (req->sreq->cmd.mode != req_mode || req->sreq->cmd.xfer > req->qsgl.size) { req->resp.cmd->response =VIRTIO_SCSI_S_OVERRUN ; +dump_cmd_resp (req);virtio_scsi_complete_req (req);continue ; }
@@ -402,6 +465,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)scsi_req_continue (req->sreq); } } +trace_virtio_scsi_handle_cmd_exit (vdev, vq); } static void virtio_scsi_get_config(VirtIODevice *vdev,
@@ -483,17 +547,22 @@ static void virtio_scsi_push_event(VirtIOSCSI *s, SCSIDevice *dev, uint32_t event, uint32_t reason) {VirtIOSCSICommon *vs =VIRTIO_SCSI_COMMON (s); -VirtIOSCSIReq *req =virtio_scsi_pop_req (s, vs->event_vq); +VirtIOSCSIReq *req;VirtIOSCSIEvent *evt;VirtIODevice *vdev =VIRTIO_DEVICE (s);int in_size; +trace_virtio_scsi_push_event_enter (vdev, vs->event_vq, event, reason); + req =virtio_scsi_pop_req (s, vs->event_vq); +if (!(vdev->status &VIRTIO_CONFIG_S_DRIVER_OK )) { +trace_virtio_scsi_push_event_unconf (vdev, vs->event_vq, event, reason);return ; }if (!req) { s->events_dropped = true; +trace_virtio_scsi_push_event_no_req (vdev, vs->event_vq, event, reason);return ; }
@@ -528,6 +597,7 @@ static void virtio_scsi_push_event(VirtIOSCSI *s, SCSIDevice *dev, evt->lun[3 ] = dev->lun &0xFF ; }virtio_scsi_complete_req (req); +trace_virtio_scsi_push_event_exit (vdev, vs->event_vq, event, reason); }static void virtio_scsi_handle_event (VirtIODevice *vdev,VirtQueue *vq)
trace-events +19 -0
@@ -1176,3 +1176,22 @@ object_class_dynamic_cast_assert(const char *type, const char *target, const cha # hw/xen/xen_pvdevice.c xen_pv_mmio_read(uint64_t addr) "WARNING: read from Xen PV Device MMIO space (address %"PRIx64")" xen_pv_mmio_write(uint64_t addr) "WARNING: write to Xen PV Device MMIO space (address %"PRIx64")" + +# hw/scsi/virtio-scsi.c +virtio_scsi_complete_req_enter(void *req) "req %p" +virtio_scsi_complete_req_exit(void *req) "req %p" +virtio_scsi_pop_req(void *req) "req %p" +virtio_scsi_handle_ctrl_enter(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_handle_ctrl_exit(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_command_complete_enter(void *req, uint32_t status, size_t resid) "req %p status %"PRIu32" resid %zu" +virtio_scsi_command_complete_exit(void *req, uint32_t status, size_t resid, uint32_t sense_len) "req %p status %"PRIu32" resid %zu sense_len %"PRIu32 +virtio_scsi_request_cancelled_enter(void *req) "req %p" +virtio_scsi_request_cancelled_exit(void *req, uint8_t resp) "req %p resp %d" +virtio_scsi_handle_cmd_enter(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_handle_cmd_exit(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_push_event_enter(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_unconf(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_no_req(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_exit(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +disable virtio_scsi_dump_cmd_resp(void *req, uint32_t sense_len, uint32_t resid, uint8_t status, uint8_t response, const char *sense_hex) "req %p sense_len %"PRIu32" resid %"PRIu32" status %d response %d sense_hex %s" +disable virtio_scsi_dump_cmd_req(void *req, uint64_t tag, int lun, const char *cdb_hex) "req %p tag %#"PRIx64" lun %d cdb_hex %s"
Signature · 1 line
1.7.1
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Il 29/08/2013 15:37, Laszlo Ersek ha scritto:
Quoted 5 lines
The events that log a hexdump of the cdb and the sense buffer are disabled by default, because they require more processing than a simple
trace_XXX()function call.Signed-off-by Laszlo Ersek <[email protected]>
trace_event_get_state doesn't work with the dtrace backend. Can you prepare v2 without those tracepoints?
Quoted 18 lines
--- hw/scsi/virtio-scsi.c | 76 +++++++++++++++++++++++++++++++++++++++++++++++-- trace-events | 19 ++++++++++++ 2 files changed, 92 insertions(+), 3 deletions(-)hw/scsi/virtio-scsi.c +1
-0@@ -15,6 +15,7 @@#include "hw/virtio/virtio-scsi.h" #include "qemu/error-report.h" +#include "trace.h" #include <hw/scsi/scsi.h> #include <block/scsi.h> #include <hw/virtio/virtio-bus.h>
hw/scsi/virtio-scsi.c static void virtio_scsi_complete_req(VirtIOSCSIReq *req) · line 66
Quoted 5 lines
hw/scsi/virtio-scsi.c +2
-0@@ -61,6 +62,8 @@ static void virtio_scsi_complete_req(VirtIOSCSIReq *req)VirtIOSCSI *s = req->dev;VirtQueue *vq = req->vq;VirtIODevice *vdev =VIRTIO_DEVICE (s); + +trace_virtio_scsi_complete_req_enter (req);
Also please add the VirtIOSCSI variable here and everywhere else.
Quoted 226 lines
hw/scsi/virtio-scsi.c +70
-3virtqueue_push (vq, &req->elem, req->qsgl.size + req->elem.in_sg[0 ].iov_len);qemu_sglist_destroy (&req->qsgl);if (req->sreq) {@@ -69,6 +72,7 @@ static void virtio_scsi_complete_req(VirtIOSCSIReq *req) }g_free (req);virtio_notify (vdev, vq); +trace_virtio_scsi_complete_req_exit (req); }static void virtio_scsi_bad_req (void )@@ -121,6 +125,7 @@ static VirtIOSCSIReq *virtio_scsi_pop_req(VirtIOSCSI *s, VirtQueue *vq) }virtio_scsi_parse_req (s, vq, req); +trace_virtio_scsi_pop_req (req);return req; }@@ -271,6 +276,7 @@ static void virtio_scsi_handle_ctrl(VirtIODevice *vdev, VirtQueue *vq)VirtIOSCSI *s = (VirtIOSCSI *)vdev;VirtIOSCSIReq *req; +trace_virtio_scsi_handle_ctrl_enter (vdev, vq);while ((req =virtio_scsi_pop_req (s, vq))) {int out_size, in_size;if (req->elem.out_num <1 || req->elem.in_num <1 ) {@@ -298,14 +304,38 @@ static void virtio_scsi_handle_ctrl(VirtIODevice *vdev, VirtQueue *vq) }virtio_scsi_complete_req (req); } +trace_virtio_scsi_handle_ctrl_exit (vdev, vq); } +#if TRACE_VIRTIO_SCSI_DUMP_CMD_RESP_ENABLED +static void dump_cmd_resp (const VirtIOSCSIReq *req) +{ +const VirtIOSCSICmdResp *cr; +uint32_t sense_len; +char *sense_hex; + +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_RESP )) { +return ; + } + cr = req->resp.cmd; + sense_len = (cr->response ==VIRTIO_SCSI_S_OK && cr->status !=GOOD ) ? +tswap32 (cr->sense_len) :0 ; + sense_hex =qemu_hexstr (cr->sense, sense_len,NULL ); +trace_virtio_scsi_dump_cmd_resp ((void *)req, sense_len,tswap32 (cr->resid), + cr->status, cr->response, sense_hex); +g_free (sense_hex); +} +#else +static inline void dump_cmd_resp (const VirtIOSCSIReq *req) {} +#endif +static void virtio_scsi_command_complete (SCSIRequest *r,uint32_t status,size_t resid) {VirtIOSCSIReq *req = r->hba_private; -uint32_t sense_len; +uint32_t sense_len =0 ; +trace_virtio_scsi_command_complete_enter (req, status, resid); req->resp.cmd->response =VIRTIO_SCSI_S_OK ; req->resp.cmd->status = status;if (req->resp.cmd->status ==GOOD ) {@@ -316,7 +346,9 @@ static void virtio_scsi_command_complete(SCSIRequest *r, uint32_t status, VIRTIO_SCSI_SENSE_SIZE); req->resp.cmd->sense_len =tswap32 (sense_len); } +dump_cmd_resp (req);virtio_scsi_complete_req (req); +trace_virtio_scsi_command_complete_exit (req, status, resid, sense_len); }static QEMUSGList *virtio_scsi_get_sg_list (SCSIRequest *r)@@ -329,24 +361,51 @@ static QEMUSGList *virtio_scsi_get_sg_list(SCSIRequest *r)static void virtio_scsi_request_cancelled (SCSIRequest *r) {VirtIOSCSIReq *req = r->hba_private; +uint8_t resp =0 ; +trace_virtio_scsi_request_cancelled_enter (req);if (!req) { -return ; + goto out; }if (req->dev->resetting) { req->resp.cmd->response =VIRTIO_SCSI_S_RESET ; }else { req->resp.cmd->response =VIRTIO_SCSI_S_ABORTED ; } + resp = req->resp.cmd->response; +dump_cmd_resp (req);virtio_scsi_complete_req (req); +out: +trace_virtio_scsi_request_cancelled_exit (req, resp); }static void virtio_scsi_fail_cmd_req (VirtIOSCSIReq *req) { req->resp.cmd->response =VIRTIO_SCSI_S_FAILURE ; +dump_cmd_resp (req);virtio_scsi_complete_req (req); } +#if TRACE_VIRTIO_SCSI_DUMP_CMD_REQ_ENABLED +static void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) +{ +const VirtIOSCSICmdReq *cr; +char *cdb_hex; + +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_REQ )) { +return ; + } + cr = req->req.cmd; + cdb_hex =qemu_hexstr (cr->cdb, cdb_size,NULL ); +trace_virtio_scsi_dump_cmd_req ((void *)req, cr->tag, +virtio_scsi_get_lun ((uint8_t *)cr->lun), + cdb_hex); +g_free (cdb_hex); +} +#else +static inline void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) {} +#endif +static void virtio_scsi_handle_cmd (VirtIODevice *vdev,VirtQueue *vq) {/* use non-QOM casts in the data path */ @@ -356,6 +415,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)VirtIOSCSIReq *req;int n; +trace_virtio_scsi_handle_cmd_enter (vdev, vq);while ((req =virtio_scsi_pop_req (s, vq))) {SCSIDevice *d;int out_size, in_size;@@ -378,9 +438,11 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq) d =virtio_scsi_device_find (s, req->req.cmd->lun);if (!d) { req->resp.cmd->response =VIRTIO_SCSI_S_BAD_TARGET ; +dump_cmd_resp (req);virtio_scsi_complete_req (req);continue ; } +dump_cmd_req (req, vs->cdb_size); req->sreq =scsi_req_new (d, req->req.cmd->tag,virtio_scsi_get_lun (req->req.cmd->lun), req->req.cmd->cdb, req);@@ -392,6 +454,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)if (req->sreq->cmd.mode != req_mode || req->sreq->cmd.xfer > req->qsgl.size) { req->resp.cmd->response =VIRTIO_SCSI_S_OVERRUN ; +dump_cmd_resp (req);virtio_scsi_complete_req (req);continue ; }@@ -402,6 +465,7 @@ static void virtio_scsi_handle_cmd(VirtIODevice *vdev, VirtQueue *vq)scsi_req_continue (req->sreq); } } +trace_virtio_scsi_handle_cmd_exit (vdev, vq); } static void virtio_scsi_get_config(VirtIODevice *vdev,@@ -483,17 +547,22 @@ static void virtio_scsi_push_event(VirtIOSCSI *s, SCSIDevice *dev, uint32_t event, uint32_t reason) {VirtIOSCSICommon *vs =VIRTIO_SCSI_COMMON (s); -VirtIOSCSIReq *req =virtio_scsi_pop_req (s, vs->event_vq); +VirtIOSCSIReq *req;VirtIOSCSIEvent *evt;VirtIODevice *vdev =VIRTIO_DEVICE (s);int in_size; +trace_virtio_scsi_push_event_enter (vdev, vs->event_vq, event, reason); + req =virtio_scsi_pop_req (s, vs->event_vq); +if (!(vdev->status &VIRTIO_CONFIG_S_DRIVER_OK )) { +trace_virtio_scsi_push_event_unconf (vdev, vs->event_vq, event, reason);return ; }if (!req) { s->events_dropped = true; +trace_virtio_scsi_push_event_no_req (vdev, vs->event_vq, event, reason);return ; }@@ -528,6 +597,7 @@ static void virtio_scsi_push_event(VirtIOSCSI *s, SCSIDevice *dev, evt->lun[3 ] = dev->lun &0xFF ; }virtio_scsi_complete_req (req); +trace_virtio_scsi_push_event_exit (vdev, vs->event_vq, event, reason); }static void virtio_scsi_handle_event (VirtIODevice *vdev,VirtQueue *vq)trace-events +19
-0@@ -1176,3 +1176,22 @@ object_class_dynamic_cast_assert(const char *type, const char *target, const cha # hw/xen/xen_pvdevice.c xen_pv_mmio_read(uint64_t addr) "WARNING: read from Xen PV Device MMIO space (address %"PRIx64")" xen_pv_mmio_write(uint64_t addr) "WARNING: write to Xen PV Device MMIO space (address %"PRIx64")" + +# hw/scsi/virtio-scsi.c +virtio_scsi_complete_req_enter(void *req) "req %p" +virtio_scsi_complete_req_exit(void *req) "req %p" +virtio_scsi_pop_req(void *req) "req %p" +virtio_scsi_handle_ctrl_enter(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_handle_ctrl_exit(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_command_complete_enter(void *req, uint32_t status, size_t resid) "req %p status %"PRIu32" resid %zu" +virtio_scsi_command_complete_exit(void *req, uint32_t status, size_t resid, uint32_t sense_len) "req %p status %"PRIu32" resid %zu sense_len %"PRIu32 +virtio_scsi_request_cancelled_enter(void *req) "req %p" +virtio_scsi_request_cancelled_exit(void *req, uint8_t resp) "req %p resp %d" +virtio_scsi_handle_cmd_enter(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_handle_cmd_exit(void *vdev, void *vq) "vdev %p vq %p" +virtio_scsi_push_event_enter(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_unconf(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_no_req(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +virtio_scsi_push_event_exit(void *vdev, void *vq, uint32_t event, uint32_t reason) "vdev %p vq %p event %#"PRIx32" reason %#"PRIx32 +disable virtio_scsi_dump_cmd_resp(void *req, uint32_t sense_len, uint32_t resid, uint8_t status, uint8_t response, const char *sense_hex) "req %p sense_len %"PRIu32" resid %"PRIu32" status %d response %d sense_hex %s" +disable virtio_scsi_dump_cmd_req(void *req, uint64_t tag, int lun, const char *cdb_hex) "req %p tag %#"PRIx64" lun %d cdb_hex %s"
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Quoted 9 lines · Paolo Bonzini
Il 29/08/2013 15:37, Laszlo Ersek ha scritto:
Quoted 5 lines
The events that log a hexdump of the cdb and the sense buffer are disabled by default, because they require more processing than a simple
trace_XXX()function call.Signed-off-by Laszlo Ersek <[email protected]>
trace_event_get_statedoesn't work with the dtrace backend. Can you prepare v2 without those tracepoints?
(a) I was just following "docs/tracing.txt"; see the last section in there.
(b) If I kill those two events, this is what you get:
Incoming request:
virtio_scsi_handle_cmd_enter vdev 0x7f1be4054468 vq 0x7f1be4054b60 virtio_scsi_pop_req req 0x7f1be5d77650 virtio_scsi_handle_cmd_exit vdev 0x7f1be4054468 vq 0x7f1be4054b60
This gives you the address of the request, so you can look up the corresponding completion. However you don't know the actual command (cdb) without "virtio_scsi_dump_cmd_req".
Then,
virtio_scsi_command_complete_enter req 0x7f1be5d77650 status 2 resid 0 virtio_scsi_complete_req_enter req 0x7f1be5d77650 virtio_scsi_complete_req_exit req 0x7f1be5d77650 virtio_scsi_command_complete_exit req 0x7f1be5d77650 status 2 resid 0 sense_len 18
this will not tell you the virtio-scsi transport response code, or the actual sense data.
(c) The way I submitted the series, the events in question are disabled in "trace-events". Check out the functions themselves: they are protected (ie. even the trace_event_get_state() calls are protected) with preprocessing directives. I did it this way because I call them in several places, and I wanted to keep the #if's centralized.
The function calls should be completely eliminated when the events are disabled in "trace-events" (which is what the patch contains). They should incur no performance penalty, and also not allow trace_event_get_state() to conflict with dtrace -- if you build with the dtrace backend, just leave these two disabled in "trace-events".
(d) I don't have more time for this, sorry.
Thanks,
Laszlo
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Il 29/08/2013 16:18, Laszlo Ersek ha scritto:
Quoted 18 lines · Paolo Bonzini
Quoted 9 lines
Il 29/08/2013 15:37, Laszlo Ersek ha scritto:
Quoted 5 lines
The events that log a hexdump of the cdb and the sense buffer are disabled by default, because they require more processing than a simple
trace_XXX()function call.Signed-off-by Laszlo Ersek <[email protected]>
trace_event_get_statedoesn't work with the dtrace backend. Can you prepare v2 without those tracepoints?(a) I was just following "
docs/tracing.txt"; see the last section in there.(b) If I kill those two events, this is what you get:
Incoming request:
Quoted 7 lines
virtio_scsi_handle_cmd_entervdev0x7f1be4054468vq0x7f1be4054b60virtio_scsi_pop_reqreq0x7f1be5d77650virtio_scsi_handle_cmd_exitvdev0x7f1be4054468vq0x7f1be4054b60This gives you the address of the request, so you can look up the corresponding completion. However you don't know the actual command (cdb) without "
virtio_scsi_dump_cmd_req".
Yes, but you can see almost all of the cdb from scsi_req_parsed and scsi_req_parsed_lba.
Quoted 7 lines
virtio_scsi_command_complete_enterreq0x7f1be5d77650status 2 resid 0virtio_scsi_complete_req_enterreq0x7f1be5d77650virtio_scsi_complete_req_exitreq0x7f1be5d77650virtio_scsi_command_complete_exitreq0x7f1be5d77650status 2 resid 0sense_len18this will not tell you the virtio-scsi transport response code, or the actual sense data.
Same here: scsi_req_build_sense can give the sense data, and we could add another tracepoint scsi_req_complete for the response code.
Quoted 5 lines
(c) The way I submitted the series, the events in question are disabled in "trace-events". Check out the functions themselves: they are protected (ie. even the
trace_event_get_state()calls are protected) with preprocessing directives. I did it this way because I call them in several places, and I wanted to keep the #if's centralized.
Tracing was supposed to remove the need for #if... :)
I'll try to salvage the patch.
Paolo
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Quoted 7 lines · Paolo Bonzini
Quoted 5 lines
(c) The way I submitted the series, the events in question are disabled in "trace-events". Check out the functions themselves: they are protected (ie. even the
trace_event_get_state()calls are protected) with preprocessing directives. I did it this way because I call them in several places, and I wanted to keep the #if's centralized.Tracing was supposed to remove the need for #if... :)
Tracing was supposed not to be broken under dtrace either I presume?
Quoted 1 line
I'll try to salvage the patch.
I won't bother next time. I wouldn't want you to waste your time on "salvaging" the clearly broken patches that I submit.
To be clear, I considered this series a favor. I don't need it to be accepted. It's easier for me to write ad-hoc debug printf()s each time. They don't depend on anything, they can print just the right set of info that I need, and they work in any component imaginable.
In comparison, the bikeshedding you repeatedly indulge in is unbearable. You keep splitting hairs and rejecting patches just because they are not in your taste; you don't need any other reason.
NB I haven't just thrown this over the wall. I spent most of today on this series and tried to cover all my bases, perusing the documentation, testing the series, making an honest effort. The one thing that I *can't* prepare for is your adoration of your own taste.
If you attribute such paramount importance to your taste, perhaps next time write the crap yourself that you tend to ask me for.
Of course there are times when I can't just ignore you and walk away. Maybe I'll look for different responsibilities if that becomes the norm.
Laszlo
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Il 29/08/2013 17:35, Laszlo Ersek ha scritto:
Quoted 5 lines · Paolo Bonzini
Quoted 1 line
I'll try to salvage the patch.
I won't bother next time. I wouldn't want you to waste your time on "salvaging" the clearly broken patches that I submit.
WTF?
The patch is clearly a good thing, or I wouldn't have asked you to send it.
However, if you don't have time to follow up on my comments, all that a maintainer can do is:
(1) ignore it and/or let it rot
(2) pick it up and gain something from a patch that isn't quite ready.
#2 is exactly the definition of salvage.
Quoted 1 line
To be clear, I considered this series a favor.
Sure, and it's very welcome. But you shouldn't expect too much from your interlocutor after writing "I don't have any more time for this".
If you don't have any more time for this, next time send me the patch privately and say it in advance before I even start reviewing it. I'll make sure you're properly acknowledged with From and Signed-off-by headers.
Paolo, glad that this time he's on the receiving edge of a flame...
Re: [Qemu-devel] [PATCH 1/2] qemu_hexstr(): hexdump a small buffer to a string, for in-line printing
In reply to Laszlo ErsekQuoted 13 lines · Laszlo Ersek
This function should primarily serve tracing needs.
Signed-off-by Laszlo Ersek <[email protected]>--- include/qemu-common.h | 11 +++++++++++ util/hexdump.c | 20 ++++++++++++++++++++ 2 files changed, 31 insertions(+), 0 deletions(-)include/qemu-common.h +0
-0
include/qemu-common.h int mod_utf8_codepoint(const char *s, size_t n, char **end); · line 438
Quoted 6 lines
include/qemu-common.h +3
-0@@ -433,6 +433,17 @@ int mod_utf8_codepoint(const char *s, size_t n, char **end);void qemu_hexdump (const char *buf,FILE *fp,const char *prefix,size_t size); +/* +* Hexdump @size bytes from @buf to a dynamically allocated string. +* If @size is NULL, then @buf can be a NULL pointer, and an empty string will
If @size is zero
Quoted 11 lines
include/qemu-common.h +8
-0+* be formatted. +* If @str_len is non-NULL, then the length of the output string (excluding the +* terminating NUL) will be stored in *@str_len. +* The output is meant to be printed on a single line, hence it contains no +* newlines, and @size should be reasonable. +*/ +char *qemu_hexstr (const void *buf,size_t size,size_t *str_len); +/* vector definitions */ #ifdef __ALTIVEC__#include <altivec.h>
[...]
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
In reply to Laszlo ErsekQuoted 4 lines · Laszlo Ersek
hw/scsi/virtio-scsi.c +4
-0+static void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) +{ +const VirtIOSCSICmdReq *cr; +char *cdb_hex;
hw/scsi/virtio-scsi.c static QEMUSGList *virtio_scsi_get_sg_list(SCSIRequest *r) · line 403
Quoted 10 lines
hw/scsi/virtio-scsi.c +10
-0+ +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_REQ )) { +return ; + } + cr = req->req.cmd; + cdb_hex =qemu_hexstr (cr->cdb, cdb_size,NULL ); +trace_virtio_scsi_dump_cmd_req ((void *)req, cr->tag, +virtio_scsi_get_lun ((uint8_t *)cr->lun), + cdb_hex); +g_free (cdb_hex);
There is a halfway solution to disable expensive trace events that works across all backends (SystemTap, stderr, etc):
if (!TRACE_VIRTIO_SCSI_DUMP_CMD_REQ_ENABLED) {
return;
}This is a compile-time constant which can be toggled with the "disable" keyword in the ./trace-events file:
disable my_expensive_event(const char *foo) "foo %s"
See the bottom of docs/tracing.txt for full documentation on the "disable" keyword.
Stefan
Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events
Quoted 23 lines · Stefan Hajnoczi
Quoted 4 lines · Laszlo Ersek
hw/scsi/virtio-scsi.c +4
-0+static void dump_cmd_req (const VirtIOSCSIReq *req,uint32_t cdb_size) +{ +const VirtIOSCSICmdReq *cr; +char *cdb_hex;hw/scsi/virtio-scsi.c static QEMUSGList *virtio_scsi_get_sg_list(SCSIRequest *r) · line 403
Quoted 10 lines
hw/scsi/virtio-scsi.c +10
-0+ +if (!trace_event_get_state (TRACE_VIRTIO_SCSI_DUMP_CMD_REQ )) { +return ; + } + cr = req->req.cmd; + cdb_hex =qemu_hexstr (cr->cdb, cdb_size,NULL ); +trace_virtio_scsi_dump_cmd_req ((void *)req, cr->tag, +virtio_scsi_get_lun ((uint8_t *)cr->lun), + cdb_hex); +g_free (cdb_hex);There is a halfway solution to disable expensive trace events that works across all backends (SystemTap, stderr, etc):
if (!TRACE_VIRTIO_SCSI_DUMP_CMD_REQ_ENABLED) { return; }
Quoted 7 lines
This is a compile-time constant which can be toggled with the "disable" keyword in the ./trace-events file:
disable
my_expensive_event(const char *foo)"foo %s"See the bottom of
docs/tracing.txtfor full documentation on the "disable" keyword.
Yes, I've read it :)
The compile-time constant is already used (just not in an if() but in a surrounding #if, snipped from the context above), and the corresponding tracepoints are already disabled in ./trace-events.
I do read documentation if it exists.
I guess I'll rework this sometime later.
Thanks,
Laszlo