Add tracing for more received packet types, cbw_state changes, and
some more SCSI callbacks. These were useful in debugging relaxed
packet ordering support.
Signed-off-by: Nicholas Piggin <npig...@gmail.com>
---
hw/usb/dev-storage.c | 23 +++++++++++++++++++++--
hw/usb/trace-events | 9 ++++++++-
2 files changed, 29 insertions(+), 3 deletions(-)
diff --git a/hw/usb/dev-storage.c b/hw/usb/dev-storage.c
index 654b9071d33..0ed39de189d 100644
--- a/hw/usb/dev-storage.c
+++ b/hw/usb/dev-storage.c
@@ -187,7 +187,7 @@ static void usb_msd_data_packet_complete(MSDState *s, int
status)
* because another request may be issued before usb_packet_complete
* returns.
*/
- trace_usb_msd_packet_complete();
+ trace_usb_msd_data_packet_complete();
s->data_packet = NULL;
p->status = status;
usb_packet_complete(&s->dev, p);
@@ -202,7 +202,7 @@ static void usb_msd_csw_packet_complete(MSDState *s, int
status)
* because another request may be issued before usb_packet_complete
* returns.
*/
- trace_usb_msd_packet_complete();
+ trace_usb_msd_csw_packet_complete();
s->csw_in_packet = NULL;
p->status = status;
usb_packet_complete(&s->dev, p);
@@ -231,7 +231,11 @@ static void usb_msd_fatal_error(MSDState *s)
static void usb_msd_copy_data(MSDState *s, USBPacket *p)
{
uint32_t len;
+
len = p->iov.size - p->actual_length;
+
+ trace_usb_msd_copy_data(s->req->tag, len);
+
if (len > s->scsi_len)
len = s->scsi_len;
usb_packet_copy(p, scsi_req_get_buf(s->req) + s->scsi_off, len);
@@ -264,6 +268,8 @@ void usb_msd_transfer_data(SCSIRequest *req, uint32_t len)
MSDState *s = DO_UPCAST(MSDState, dev.qdev, req->bus->qbus.parent);
USBPacket *p = s->data_packet;
+ trace_usb_msd_transfer_data(req->tag, len);
+
if (s->cbw_state == USB_MSD_CBW_DATAIN) {
if (req->cmd.mode == SCSI_XFER_TO_DEV) {
usb_msd_fatal_error(s);
@@ -324,11 +330,13 @@ void usb_msd_command_complete(SCSIRequest *req, size_t
resid)
}
if (s->data_len == 0) {
s->cbw_state = USB_MSD_CBW_CSW;
+ trace_usb_msd_cbw_state(s->cbw_state);
}
/* USB_RET_SUCCESS status clears previous ASYNC status */
usb_msd_data_packet_complete(s, USB_RET_SUCCESS);
} else if (s->data_len == 0) {
s->cbw_state = USB_MSD_CBW_CSW;
+ trace_usb_msd_cbw_state(s->cbw_state);
}
if (s->cbw_state == USB_MSD_CBW_CSW) {
@@ -336,6 +344,7 @@ void usb_msd_command_complete(SCSIRequest *req, size_t
resid)
if (p) {
usb_msd_send_status(s, p);
s->cbw_state = USB_MSD_CBW_NONE;
+ trace_usb_msd_cbw_state(s->cbw_state);
/* USB_RET_SUCCESS status clears previous ASYNC status */
usb_msd_csw_packet_complete(s, USB_RET_SUCCESS);
}
@@ -379,6 +388,7 @@ void usb_msd_handle_reset(USBDevice *dev)
memset(&s->csw, 0, sizeof(s->csw));
s->cbw_state = USB_MSD_CBW_NONE;
+ trace_usb_msd_cbw_state(s->cbw_state);
s->needs_reset = false;
}
@@ -429,6 +439,8 @@ static void usb_msd_cancel_io(USBDevice *dev, USBPacket *p)
{
MSDState *s = USB_STORAGE_DEV(dev);
+ trace_usb_msd_cancel_io();
+
if (p == s->data_packet) {
s->data_packet = NULL;
if (s->req) {
@@ -516,6 +528,7 @@ static void usb_msd_handle_data_out(USBDevice *dev,
USBPacket *p)
}
trace_usb_msd_cmd_submit(cbw.lun, tag, cbw.flags,
cbw.cmd_len, s->data_len);
+ trace_usb_msd_cbw_state(s->cbw_state);
assert(le32_to_cpu(s->csw.residue) == 0);
assert(s->scsi_len == 0);
s->req = scsi_req_new(scsi_dev, tag, cbw.lun,
@@ -553,6 +566,7 @@ static void usb_msd_handle_data_out(USBDevice *dev,
USBPacket *p)
s->data_len -= len;
if (s->data_len == 0) {
s->cbw_state = USB_MSD_CBW_CSW;
+ trace_usb_msd_cbw_state(s->cbw_state);
}
}
}
@@ -579,6 +593,7 @@ static void usb_msd_handle_data_in(USBDevice *dev,
USBPacket *p)
switch (s->cbw_state) {
case USB_MSD_CBW_NONE:
+ trace_usb_msd_unknown_in(p->iov.size);
if (s->unknown_in_packet) {
qemu_log_mask(LOG_GUEST_ERROR, "usb-msd: second IN packet was"
"received before CBW\n");
@@ -590,6 +605,7 @@ static void usb_msd_handle_data_in(USBDevice *dev,
USBPacket *p)
break;
case USB_MSD_CBW_DATAOUT:
+ trace_usb_msd_csw_in();
if (s->unknown_in_packet) {
error_report("usb-msd: unknown_in_packet in DATAOUT state");
goto fail;
@@ -610,6 +626,7 @@ static void usb_msd_handle_data_in(USBDevice *dev,
USBPacket *p)
break;
case USB_MSD_CBW_CSW:
+ trace_usb_msd_csw_in();
if (s->unknown_in_packet) {
error_report("usb-msd: unknown_in_packet in DATAOUT state");
goto fail;
@@ -626,6 +643,7 @@ static void usb_msd_handle_data_in(USBDevice *dev,
USBPacket *p)
} else {
usb_msd_send_status(s, p);
s->cbw_state = USB_MSD_CBW_NONE;
+ trace_usb_msd_cbw_state(s->cbw_state);
}
break;
@@ -648,6 +666,7 @@ static void usb_msd_handle_data_in(USBDevice *dev,
USBPacket *p)
s->data_len -= len;
if (s->data_len == 0) {
s->cbw_state = USB_MSD_CBW_CSW;
+ trace_usb_msd_cbw_state(s->cbw_state);
}
}
}
diff --git a/hw/usb/trace-events b/hw/usb/trace-events
index dd04f14add1..688f7ba0b3d 100644
--- a/hw/usb/trace-events
+++ b/hw/usb/trace-events
@@ -264,12 +264,19 @@ usb_msd_maxlun(unsigned maxlun) "%d"
usb_msd_send_status(unsigned status, unsigned tag, size_t size) "status %d,
tag 0x%x, len %zd"
usb_msd_data_in(unsigned packet, unsigned remaining, unsigned total) "%d/%d
(scsi %d)"
usb_msd_data_out(unsigned packet, unsigned remaining) "%d/%d"
+usb_msd_unknown_in(unsigned packet) "%d"
+usb_msd_csw_in(void) ""
usb_msd_packet_async(void) ""
-usb_msd_packet_complete(void) ""
+usb_msd_data_packet_complete(void) ""
+usb_msd_csw_packet_complete(void) ""
usb_msd_cmd_submit(unsigned lun, unsigned tag, unsigned flags, unsigned len,
unsigned data_len) "lun %u, tag 0x%x, flags 0x%08x, len %d, data-len %d"
usb_msd_cmd_complete(unsigned status, unsigned tag) "status %d, tag 0x%x"
+usb_msd_copy_data(unsigned tag, unsigned len) "tag 0x%x len %d"
+usb_msd_transfer_data(unsigned tag, unsigned len) "tag 0x%x len %d"
usb_msd_cmd_cancel(unsigned tag) "tag 0x%x"
+usb_msd_cancel_io(void) ""
usb_msd_fatal_error(void) ""
+usb_msd_cbw_state(unsigned cbw_state) "cbw-state %d"
# dev-uas.c
usb_uas_reset(int addr) "dev %d"
--
2.47.1
