[PATCH 0/6] usb: fix some guest-triggerable asserts

[PATCH 0/6] usb: fix some guest-triggerable asserts

[Gerd Hoffmann]

Also kill DPRINTF in usb-storage.c

Gerd Hoffmann (6):
  usb-storage: switch trace events
  usb-storage: add commandlog property
  usb-storage: use bool for removable property
  usb-storage: fill csw on cancel
  xhci: fix guest triggerable assert
  xhci: move sanity checks

 hw/usb/dev-storage.c | 60 +++++++++++++++++++++-----------------------
 hw/usb/hcd-xhci.c    | 11 +++++---
 hw/usb/trace-events  | 12 +++++++++
 3 files changed, 48 insertions(+), 35 deletions(-)

-- 
2.27.0

[PATCH 1/6] usb-storage: switch trace events

[Gerd Hoffmann]

Replace most DPRINTF macros with trace events.
Drop some DPRINTF macros.

Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/dev-storage.c | 42 +++++++++++++++++-------------------------
 hw/usb/trace-events  | 12 ++++++++++++
 2 files changed, 29 insertions(+), 25 deletions(-)

diff --git a/hw/usb/dev-storage.c b/hw/usb/dev-storage.c
index 648340323f68..e317cde8fd48 100644
--- a/hw/usb/dev-storage.c
+++ b/hw/usb/dev-storage.c
@@ -23,16 +23,10 @@
 #include "qapi/visitor.h"
 #include "qemu/cutils.h"
 #include "qom/object.h"
+#include "trace.h"
 
 //#define DEBUG_MSD
 
-#ifdef DEBUG_MSD
-#define DPRINTF(fmt, ...) \
-do { printf("usb-msd: " fmt , ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) do {} while(0)
-#endif
-
 /* USB requests.  */
 #define MassStorageReset  0xff
 #define GetMaxLun         0xfe
@@ -245,8 +239,8 @@ static void usb_msd_send_status(MSDState *s, USBPacket *p)
 {
     int len;
 
-    DPRINTF("Command status %d tag 0x%x, len %zd\n",
-            s->csw.status, le32_to_cpu(s->csw.tag), p->iov.size);
+    trace_usb_msd_send_status(s->csw.status, le32_to_cpu(s->csw.tag),
+                              p->iov.size);
 
     assert(s->csw.sig == cpu_to_le32(0x53425355));
     len = MIN(sizeof(s->csw), p->iov.size);
@@ -261,7 +255,7 @@ static void usb_msd_packet_complete(MSDState *s)
     /* Set s->packet to NULL before calling usb_packet_complete
        because another request may be issued before
        usb_packet_complete returns.  */
-    DPRINTF("Packet complete %p\n", p);
+    trace_usb_msd_packet_complete();
     s->packet = NULL;
     usb_packet_complete(&s->dev, p);
 }
@@ -289,7 +283,7 @@ static void usb_msd_command_complete(SCSIRequest *req, uint32_t status, size_t r
     MSDState *s = DO_UPCAST(MSDState, dev.qdev, req->bus->qbus.parent);
     USBPacket *p = s->packet;
 
-    DPRINTF("Command complete %d tag 0x%x\n", status, req->tag);
+    trace_usb_msd_cmd_complete(status, req->tag);
 
     s->csw.sig = cpu_to_le32(0x53425355);
     s->csw.tag = cpu_to_le32(req->tag);
@@ -331,6 +325,8 @@ static void usb_msd_request_cancelled(SCSIRequest *req)
 {
     MSDState *s = DO_UPCAST(MSDState, dev.qdev, req->bus->qbus.parent);
 
+    trace_usb_msd_cmd_cancel(req->tag);
+
     if (req == s->req) {
         scsi_req_unref(s->req);
         s->req = NULL;
@@ -342,7 +338,7 @@ static void usb_msd_handle_reset(USBDevice *dev)
 {
     MSDState *s = (MSDState *)dev;
 
-    DPRINTF("Reset\n");
+    trace_usb_msd_reset();
     if (s->req) {
         scsi_req_cancel(s->req);
     }
@@ -388,7 +384,7 @@ static void usb_msd_handle_control(USBDevice *dev, USBPacket *p,
             }
             maxlun++;
         }
-        DPRINTF("MaxLun %d\n", maxlun);
+        trace_usb_msd_maxlun(maxlun);
         data[0] = maxlun;
         p->actual_length = 1;
         break;
@@ -436,7 +432,6 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
                              le32_to_cpu(cbw.sig));
                 goto fail;
             }
-            DPRINTF("Command on LUN %d\n", cbw.lun);
             scsi_dev = scsi_device_find(&s->bus, 0, 0, cbw.lun);
             if (scsi_dev == NULL) {
                 error_report("usb-msd: Bad LUN %d", cbw.lun);
@@ -451,8 +446,8 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
             } else {
                 s->mode = USB_MSDM_DATAOUT;
             }
-            DPRINTF("Command tag 0x%x flags %08x len %d data %d\n",
-                    tag, cbw.flags, cbw.cmd_len, s->data_len);
+            trace_usb_msd_cmd_submit(cbw.lun, tag, cbw.flags,
+                                     cbw.cmd_len, s->data_len);
             assert(le32_to_cpu(s->csw.residue) == 0);
             s->scsi_len = 0;
             s->req = scsi_req_new(scsi_dev, tag, cbw.lun, cbw.cmd, NULL);
@@ -466,7 +461,7 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
             break;
 
         case USB_MSDM_DATAOUT:
-            DPRINTF("Data out %zd/%d\n", p->iov.size, s->data_len);
+            trace_usb_msd_data_out(p->iov.size, s->data_len);
             if (p->iov.size > s->data_len) {
                 goto fail;
             }
@@ -488,14 +483,13 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
                 }
             }
             if (p->actual_length < p->iov.size) {
-                DPRINTF("Deferring packet %p [wait data-out]\n", p);
+                trace_usb_msd_packet_async();
                 s->packet = p;
                 p->status = USB_RET_ASYNC;
             }
             break;
 
         default:
-            DPRINTF("Unexpected write (len %zd)\n", p->iov.size);
             goto fail;
         }
         break;
@@ -510,6 +504,7 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
                 goto fail;
             }
             /* Waiting for SCSI write to complete.  */
+            trace_usb_msd_packet_async();
             s->packet = p;
             p->status = USB_RET_ASYNC;
             break;
@@ -521,7 +516,7 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
 
             if (s->req) {
                 /* still in flight */
-                DPRINTF("Deferring packet %p [wait status]\n", p);
+                trace_usb_msd_packet_async();
                 s->packet = p;
                 p->status = USB_RET_ASYNC;
             } else {
@@ -531,8 +526,7 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
             break;
 
         case USB_MSDM_DATAIN:
-            DPRINTF("Data in %zd/%d, scsi_len %d\n",
-                    p->iov.size, s->data_len, s->scsi_len);
+            trace_usb_msd_data_in(p->iov.size, s->data_len, s->scsi_len);
             if (s->scsi_len) {
                 usb_msd_copy_data(s, p);
             }
@@ -550,20 +544,18 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
                 }
             }
             if (p->actual_length < p->iov.size && s->mode == USB_MSDM_DATAIN) {
-                DPRINTF("Deferring packet %p [wait data-in]\n", p);
+                trace_usb_msd_packet_async();
                 s->packet = p;
                 p->status = USB_RET_ASYNC;
             }
             break;
 
         default:
-            DPRINTF("Unexpected read (len %zd)\n", p->iov.size);
             goto fail;
         }
         break;
 
     default:
-        DPRINTF("Bad token\n");
     fail:
         p->status = USB_RET_STALL;
         break;
diff --git a/hw/usb/trace-events b/hw/usb/trace-events
index a3292d46248f..38e05fc7f4db 100644
--- a/hw/usb/trace-events
+++ b/hw/usb/trace-events
@@ -252,6 +252,18 @@ usb_hub_attach(int addr, int nr) "dev %d, port %d"
 usb_hub_detach(int addr, int nr) "dev %d, port %d"
 usb_hub_status_report(int addr, int status) "dev %d, status 0x%x"
 
+# dev-storage.c
+usb_msd_reset(void) ""
+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_packet_async(void) ""
+usb_msd_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_cmd_cancel(unsigned tag) "tag 0x%x"
+
 # dev-uas.c
 usb_uas_reset(int addr) "dev %d"
 usb_uas_command(int addr, uint16_t tag, int lun, uint32_t lun64_1, uint32_t lun64_2) "dev %d, tag 0x%x, lun %d, lun64 0x%08x-0x%08x"
-- 
2.27.0

Re: [PATCH 1/6] usb-storage: switch trace events

[Philippe Mathieu-Daudé]

On 11/5/20 2:41 PM, Gerd Hoffmann wrote:
> Replace most DPRINTF macros with trace events.
> Drop some DPRINTF macros.
> 
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  hw/usb/dev-storage.c | 42 +++++++++++++++++-------------------------
>  hw/usb/trace-events  | 12 ++++++++++++
>  2 files changed, 29 insertions(+), 25 deletions(-)
...

> diff --git a/hw/usb/trace-events b/hw/usb/trace-events
> index a3292d46248f..38e05fc7f4db 100644
> --- a/hw/usb/trace-events
> +++ b/hw/usb/trace-events
> @@ -252,6 +252,18 @@ usb_hub_attach(int addr, int nr) "dev %d, port %d"
>  usb_hub_detach(int addr, int nr) "dev %d, port %d"
>  usb_hub_status_report(int addr, int status) "dev %d, status 0x%x"
>  
> +# dev-storage.c
> +usb_msd_reset(void) ""
> +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_packet_async(void) ""
> +usb_msd_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"

Using '%u' format for unsigned type:
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

[PATCH 2/6] usb-storage: add commandlog property

[Gerd Hoffmann]

Add property so scsi command logging can be switched
at runtime instead of compile time.

Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/dev-storage.c | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/hw/usb/dev-storage.c b/hw/usb/dev-storage.c
index e317cde8fd48..d5cc6137443c 100644
--- a/hw/usb/dev-storage.c
+++ b/hw/usb/dev-storage.c
@@ -25,8 +25,6 @@
 #include "qom/object.h"
 #include "trace.h"
 
-//#define DEBUG_MSD
-
 /* USB requests.  */
 #define MassStorageReset  0xff
 #define GetMaxLun         0xfe
@@ -59,6 +57,7 @@ struct MSDState {
     /* usb-storage only */
     BlockConf conf;
     uint32_t removable;
+    bool commandlog;
     SCSIDevice *scsi_dev;
 };
 typedef struct MSDState MSDState;
@@ -451,9 +450,9 @@ static void usb_msd_handle_data(USBDevice *dev, USBPacket *p)
             assert(le32_to_cpu(s->csw.residue) == 0);
             s->scsi_len = 0;
             s->req = scsi_req_new(scsi_dev, tag, cbw.lun, cbw.cmd, NULL);
-#ifdef DEBUG_MSD
-            scsi_req_print(s->req);
-#endif
+            if (s->commandlog) {
+                scsi_req_print(s->req);
+            }
             len = scsi_req_enqueue(s->req);
             if (len) {
                 scsi_req_continue(s->req);
@@ -684,6 +683,7 @@ static Property msd_properties[] = {
     DEFINE_BLOCK_PROPERTIES(MSDState, conf),
     DEFINE_BLOCK_ERROR_PROPERTIES(MSDState, conf),
     DEFINE_PROP_BIT("removable", MSDState, removable, 0, false),
+    DEFINE_PROP_BOOL("commandlog", MSDState, commandlog, false),
     DEFINE_PROP_END_OF_LIST(),
 };
 
-- 
2.27.0

Re: [PATCH 2/6] usb-storage: add commandlog property

[Philippe Mathieu-Daudé]

On 11/5/20 2:41 PM, Gerd Hoffmann wrote:
> Add property so scsi command logging can be switched
> at runtime instead of compile time.
> 
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  hw/usb/dev-storage.c | 10 +++++-----
>  1 file changed, 5 insertions(+), 5 deletions(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

[PATCH 3/6] usb-storage: use bool for removable property

[Gerd Hoffmann]

Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/dev-storage.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/hw/usb/dev-storage.c b/hw/usb/dev-storage.c
index d5cc6137443c..360e8ca8f2bd 100644
--- a/hw/usb/dev-storage.c
+++ b/hw/usb/dev-storage.c
@@ -56,7 +56,7 @@ struct MSDState {
     USBPacket *packet;
     /* usb-storage only */
     BlockConf conf;
-    uint32_t removable;
+    bool removable;
     bool commandlog;
     SCSIDevice *scsi_dev;
 };
@@ -682,7 +682,7 @@ static const VMStateDescription vmstate_usb_msd = {
 static Property msd_properties[] = {
     DEFINE_BLOCK_PROPERTIES(MSDState, conf),
     DEFINE_BLOCK_ERROR_PROPERTIES(MSDState, conf),
-    DEFINE_PROP_BIT("removable", MSDState, removable, 0, false),
+    DEFINE_PROP_BOOL("removable", MSDState, removable, false),
     DEFINE_PROP_BOOL("commandlog", MSDState, commandlog, false),
     DEFINE_PROP_END_OF_LIST(),
 };
-- 
2.27.0

Re: [PATCH 3/6] usb-storage: use bool for removable property

[Philippe Mathieu-Daudé]

On 11/5/20 2:41 PM, Gerd Hoffmann wrote:
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  hw/usb/dev-storage.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

[PATCH 4/6] usb-storage: fill csw on cancel

[Gerd Hoffmann]

When scsi requests are canceled fill the csw
(command status word) accordingly.

Buglink: https://bugs.launchpad.net/qemu/+bug/1901981
Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/dev-storage.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/hw/usb/dev-storage.c b/hw/usb/dev-storage.c
index 360e8ca8f2bd..f0f005869d25 100644
--- a/hw/usb/dev-storage.c
+++ b/hw/usb/dev-storage.c
@@ -327,6 +327,10 @@ static void usb_msd_request_cancelled(SCSIRequest *req)
     trace_usb_msd_cmd_cancel(req->tag);
 
     if (req == s->req) {
+        s->csw.sig = cpu_to_le32(0x53425355);
+        s->csw.tag = cpu_to_le32(req->tag);
+        s->csw.status = 1; /* error */
+
         scsi_req_unref(s->req);
         s->req = NULL;
         s->scsi_len = 0;
-- 
2.27.0

[PATCH 5/6] xhci: fix guest triggerable assert

[Gerd Hoffmann]

We didn't start any work yet so we can just return
at that point instead of asserting.

Buglink: https://bugs.launchpad.net/qemu/+bug/1883732
Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/hcd-xhci.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/hw/usb/hcd-xhci.c b/hw/usb/hcd-xhci.c
index 79ce5c4be6c4..d00bb0141dac 100644
--- a/hw/usb/hcd-xhci.c
+++ b/hw/usb/hcd-xhci.c
@@ -1904,7 +1904,9 @@ static void xhci_kick_epctx(XHCIEPContext *epctx, unsigned int streamid)
         streamid = 0;
         xhci_set_ep_state(xhci, epctx, NULL, EP_RUNNING);
     }
-    assert(ring->dequeue != 0);
+    if (!ring->dequeue) {
+        return;
+    }
 
     epctx->kick_active++;
     while (1) {
-- 
2.27.0

Re: [PATCH 5/6] xhci: fix guest triggerable assert

[Philippe Mathieu-Daudé]

On 11/5/20 2:41 PM, Gerd Hoffmann wrote:
> We didn't start any work yet so we can just return
> at that point instead of asserting.
> 
> Buglink: https://bugs.launchpad.net/qemu/+bug/1883732
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  hw/usb/hcd-xhci.c | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

[PATCH 6/6] xhci: move sanity checks

[Gerd Hoffmann]

The v variable goes negative for reg < 0x20.  Reorder the code
to first sanity check then calculate v and assign intr to make
sanity checkers happy.

Buglink: https://bugs.launchpad.net/qemu/+bug/1902112
Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
 hw/usb/hcd-xhci.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/hw/usb/hcd-xhci.c b/hw/usb/hcd-xhci.c
index d00bb0141dac..6dfb17cbe915 100644
--- a/hw/usb/hcd-xhci.c
+++ b/hw/usb/hcd-xhci.c
@@ -3010,14 +3010,17 @@ static void xhci_runtime_write(void *ptr, hwaddr reg,
                                uint64_t val, unsigned size)
 {
     XHCIState *xhci = ptr;
-    int v = (reg - 0x20) / 0x20;
-    XHCIInterrupter *intr = &xhci->intr[v];
+    XHCIInterrupter *intr;
+    int v;
+
     trace_usb_xhci_runtime_write(reg, val);
 
     if (reg < 0x20) {
         trace_usb_xhci_unimplemented("runtime write", reg);
         return;
     }
+    v = (reg - 0x20) / 0x20;
+    intr = &xhci->intr[v];
 
     switch (reg & 0x1f) {
     case 0x00: /* IMAN */
-- 
2.27.0

Re: [PATCH 6/6] xhci: move sanity checks

[Philippe Mathieu-Daudé]

On 11/5/20 2:41 PM, Gerd Hoffmann wrote:
> The v variable goes negative for reg < 0x20.  Reorder the code
> to first sanity check then calculate v and assign intr to make
> sanity checkers happy.
> 
> Buglink: https://bugs.launchpad.net/qemu/+bug/1902112
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
>  hw/usb/hcd-xhci.c | 7 +++++--
>  1 file changed, 5 insertions(+), 2 deletions(-)

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>