From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:53131) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1VF2kk-0005DD-7u for qemu-devel@nongnu.org; Thu, 29 Aug 2013 09:59:20 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1VF2ke-0007RQ-65 for qemu-devel@nongnu.org; Thu, 29 Aug 2013 09:59:14 -0400 Received: from mx1.redhat.com ([209.132.183.28]:31207) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1VF2kd-0007Qs-VS for qemu-devel@nongnu.org; Thu, 29 Aug 2013 09:59:08 -0400 Received: from int-mx12.intmail.prod.int.phx2.redhat.com (int-mx12.intmail.prod.int.phx2.redhat.com [10.5.11.25]) by mx1.redhat.com (8.14.4/8.14.4) with ESMTP id r7TDx65B027872 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK) for ; Thu, 29 Aug 2013 09:59:06 -0400 Message-ID: <521F53A6.7070200@redhat.com> Date: Thu, 29 Aug 2013 15:59:02 +0200 From: Paolo Bonzini MIME-Version: 1.0 References: <521F4E76.2090507@redhat.com> <1377783470-8981-2-git-send-email-lersek@redhat.com> In-Reply-To: <1377783470-8981-2-git-send-email-lersek@redhat.com> Content-Type: text/plain; charset=ISO-8859-15 Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] [PATCH 2/2] add some virtio-scsi trace events List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Laszlo Ersek Cc: qemu-devel@nongnu.org Il 29/08/2013 15:37, Laszlo Ersek ha scritto: > 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 trace_event_get_state doesn't work with the dtrace backend. Can you prepare v2 without those tracepoints? > --- > hw/scsi/virtio-scsi.c | 76 +++++++++++++++++++++++++++++++++++++++++++++++-- > trace-events | 19 ++++++++++++ > 2 files changed, 92 insertions(+), 3 deletions(-) > > diff --git a/hw/scsi/virtio-scsi.c b/hw/scsi/virtio-scsi.c > index 05da56b..22677f7 100644 > --- a/hw/scsi/virtio-scsi.c > +++ b/hw/scsi/virtio-scsi.c > @@ -15,6 +15,7 @@ > > #include "hw/virtio/virtio-scsi.h" > #include "qemu/error-report.h" > +#include "trace.h" > #include > #include > #include > @@ -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. > 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) > diff --git a/trace-events b/trace-events > index 3856b5c..68eebab 100644 > --- a/trace-events > +++ b/trace-events > @@ -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" >