[PATCH 0/3] scsi: infinite guest hangs with scsi-disk

[PATCH 0/3] scsi: infinite guest hangs with scsi-disk

[Hannes Reinecke]

Hi all,

one of our customers reported an infinite guest hang following an FC link loss  when using scsi-disk.
Problem is that scsi-disk issues SG_IO command with a timeout of UINT_MAX, which essentially signals
'no timeout' to the host kernel. So if the command gets lost eg during an unexpected link loss the
HBA driver will never attempt to abort or return the command. Hence the guest will hang forever, and
the only way to resolve things is to reboot the host.

To solve it this patchset adds an 'io_timeout' parameter to scsi-disk and scsi-generic, which allows
the admin to specify a command timeout for SG_IO request. It is initialized to 30 seconds to avoid the
infinite hang as mentioned above.

As usual, comments and reviews are welcome.

Hannes Reinecke (3):
  virtio-scsi: trace events
  scsi: make io_timeout configurable
  scsi: add tracing for SG_IO commands

 hw/scsi/scsi-disk.c    |  9 ++++++---
 hw/scsi/scsi-generic.c | 25 ++++++++++++++++++-------
 hw/scsi/trace-events   | 13 +++++++++++++
 hw/scsi/virtio-scsi.c  | 30 +++++++++++++++++++++++++++++-
 include/hw/scsi/scsi.h |  4 +++-
 5 files changed, 69 insertions(+), 12 deletions(-)

-- 
2.16.4

[PATCH 1/3] virtio-scsi: trace events

[Hannes Reinecke]

Add trace events for virtio command and response tracing.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 hw/scsi/trace-events  |  9 +++++++++
 hw/scsi/virtio-scsi.c | 30 +++++++++++++++++++++++++++++-
 2 files changed, 38 insertions(+), 1 deletion(-)

diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index 9a4a60ca63..0e0aa9847d 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -294,6 +294,15 @@ lsi_awoken(void) "Woken by SIGP"
 lsi_reg_read(const char *name, int offset, uint8_t ret) "Read reg %s 0x%x = 0x%02x"
 lsi_reg_write(const char *name, int offset, uint8_t val) "Write reg %s 0x%x = 0x%02x"
 
+# virtio-scsi.c
+virtio_scsi_cmd_req(int lun, uint32_t tag, uint8_t cmd) "virtio_scsi_cmd_req lun=%u tag=0x%x cmd=0x%x"
+virtio_scsi_cmd_resp(int lun, uint32_t tag, int response, uint8_t status) "virtio_scsi_cmd_resp lun=%u tag=0x%x response=%d status=0x%x"
+virtio_scsi_tmf_req(int lun, uint32_t tag, int subtype) "virtio_scsi_tmf_req lun=%u tag=0x%x subtype=%d"
+virtio_scsi_tmf_resp(int lun, uint32_t tag, int response) "virtio_scsi_tmf_resp lun=%u tag=0x%x response=%d"
+virtio_scsi_an_req(int lun, uint32_t event_requested) "virtio_scsi_an_req lun=%u event_requested=0x%x"
+virtio_scsi_an_resp(int lun, int response) "virtio_scsi_an_resp lun=%u response=%d"
+virtio_scsi_event(int lun, int event, int reason) "virtio_scsi_event lun=%u event=%d reason=%d"
+
 # scsi-disk.c
 scsi_disk_check_condition(uint32_t tag, uint8_t key, uint8_t asc, uint8_t ascq) "Command complete tag=0x%x sense=%d/%d/%d"
 scsi_disk_read_complete(uint32_t tag, size_t size) "Data ready tag=0x%x len=%zd"
diff --git a/hw/scsi/virtio-scsi.c b/hw/scsi/virtio-scsi.c
index 3a71ea7097..c9873d5af7 100644
--- a/hw/scsi/virtio-scsi.c
+++ b/hw/scsi/virtio-scsi.c
@@ -27,6 +27,7 @@
 #include "scsi/constants.h"
 #include "hw/virtio/virtio-bus.h"
 #include "hw/virtio/virtio-access.h"
+#include "trace.h"
 
 static inline int virtio_scsi_get_lun(uint8_t *lun)
 {
@@ -239,7 +240,11 @@ static void virtio_scsi_cancel_notify(Notifier *notifier, void *data)
                                                notifier);
 
     if (--n->tmf_req->remaining == 0) {
-        virtio_scsi_complete_req(n->tmf_req);
+        VirtIOSCSIReq *req = n->tmf_req;
+
+        trace_virtio_scsi_tmf_resp(virtio_scsi_get_lun(req->req.tmf.lun),
+                                   req->req.tmf.tag, req->resp.tmf.response);
+        virtio_scsi_complete_req(req);
     }
     g_free(n);
 }
@@ -273,6 +278,9 @@ static int virtio_scsi_do_tmf(VirtIOSCSI *s, VirtIOSCSIReq *req)
     req->req.tmf.subtype =
         virtio_tswap32(VIRTIO_DEVICE(s), req->req.tmf.subtype);
 
+    trace_virtio_scsi_tmf_req(virtio_scsi_get_lun(req->req.tmf.lun),
+                              req->req.tmf.tag, req->req.tmf.subtype);
+
     switch (req->req.tmf.subtype) {
     case VIRTIO_SCSI_T_TMF_ABORT_TASK:
     case VIRTIO_SCSI_T_TMF_QUERY_TASK:
@@ -422,11 +430,23 @@ static void virtio_scsi_handle_ctrl_req(VirtIOSCSI *s, VirtIOSCSIReq *req)
             virtio_scsi_bad_req(req);
             return;
         } else {
+            req->req.an.event_requested =
+                virtio_tswap32(VIRTIO_DEVICE(s), req->req.an.event_requested);
+            trace_virtio_scsi_an_req(virtio_scsi_get_lun(req->req.an.lun),
+                                     req->req.an.event_requested);
             req->resp.an.event_actual = 0;
             req->resp.an.response = VIRTIO_SCSI_S_OK;
         }
     }
     if (r == 0) {
+        if (type == VIRTIO_SCSI_T_TMF)
+            trace_virtio_scsi_tmf_resp(virtio_scsi_get_lun(req->req.tmf.lun),
+                                       req->req.tmf.tag,
+                                       req->resp.tmf.response);
+        else if (type == VIRTIO_SCSI_T_AN_QUERY ||
+                 type == VIRTIO_SCSI_T_AN_SUBSCRIBE)
+            trace_virtio_scsi_an_resp(virtio_scsi_get_lun(req->req.an.lun),
+                                      req->resp.an.response);
         virtio_scsi_complete_req(req);
     } else {
         assert(r == -EINPROGRESS);
@@ -462,6 +482,10 @@ static void virtio_scsi_handle_ctrl(VirtIODevice *vdev, VirtQueue *vq)
 
 static void virtio_scsi_complete_cmd_req(VirtIOSCSIReq *req)
 {
+    trace_virtio_scsi_cmd_resp(virtio_scsi_get_lun(req->req.cmd.lun),
+                               req->req.cmd.tag,
+                               req->resp.cmd.response,
+                               req->resp.cmd.status);
     /* Sense data is not in req->resp and is copied separately
      * in virtio_scsi_command_complete.
      */
@@ -559,6 +583,8 @@ static int virtio_scsi_handle_cmd_req_prepare(VirtIOSCSI *s, VirtIOSCSIReq *req)
             return -EINVAL;
         }
     }
+    trace_virtio_scsi_cmd_req(virtio_scsi_get_lun(req->req.cmd.lun),
+                              req->req.cmd.tag, req->req.cmd.cdb[0]);
 
     d = virtio_scsi_device_find(s, req->req.cmd.lun);
     if (!d) {
@@ -758,6 +784,8 @@ void virtio_scsi_push_event(VirtIOSCSI *s, SCSIDevice *dev,
         }
         evt->lun[3] = dev->lun & 0xFF;
     }
+    trace_virtio_scsi_event(virtio_scsi_get_lun(evt->lun), event, reason);
+     
     virtio_scsi_complete_req(req);
 }
 
-- 
2.16.4

[PATCH 2/3] scsi: make io_timeout configurable

[Hannes Reinecke]

The current code sets an infinite timeout on SG_IO requests,
causing the guest to stall if the host experiences a frame
loss.
This patch adds an 'io_timeout' parameter for SCSIDevice to
make the SG_IO timeout configurable, and also shortens the
default timeout to 30 seconds to avoid infinite stalls.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 hw/scsi/scsi-disk.c    |  6 ++++--
 hw/scsi/scsi-generic.c | 17 +++++++++++------
 include/hw/scsi/scsi.h |  4 +++-
 3 files changed, 18 insertions(+), 9 deletions(-)

diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c
index e859534eaf..2959526b52 100644
--- a/hw/scsi/scsi-disk.c
+++ b/hw/scsi/scsi-disk.c
@@ -2604,7 +2604,7 @@ static int get_device_type(SCSIDiskState *s)
     cmd[4] = sizeof(buf);
 
     ret = scsi_SG_IO_FROM_DEV(s->qdev.conf.blk, cmd, sizeof(cmd),
-                              buf, sizeof(buf));
+                              buf, sizeof(buf), s->qdev.io_timeout);
     if (ret < 0) {
         return -1;
     }
@@ -2765,7 +2765,7 @@ static BlockAIOCB *scsi_block_do_sgio(SCSIBlockReq *req,
     /* The rest is as in scsi-generic.c.  */
     io_header->mx_sb_len = sizeof(r->req.sense);
     io_header->sbp = r->req.sense;
-    io_header->timeout = UINT_MAX;
+    io_header->timeout = s->qdev.io_timeout * 1000;
     io_header->usr_ptr = r;
     io_header->flags |= SG_FLAG_DIRECT_IO;
 
@@ -3083,6 +3083,8 @@ static Property scsi_block_properties[] = {
                        DEFAULT_MAX_IO_SIZE),
     DEFINE_PROP_INT32("scsi_version", SCSIDiskState, qdev.default_scsi_version,
                       -1),
+    DEFINE_PROP_UINT32("io_timeout", SCSIDiskState, qdev.io_timeout,
+                       DEFAULT_IO_TIMEOUT),
     DEFINE_PROP_END_OF_LIST(),
 };
 
diff --git a/hw/scsi/scsi-generic.c b/hw/scsi/scsi-generic.c
index 2cb23ca891..e07924b3d7 100644
--- a/hw/scsi/scsi-generic.c
+++ b/hw/scsi/scsi-generic.c
@@ -114,6 +114,8 @@ static int execute_command(BlockBackend *blk,
                            SCSIGenericReq *r, int direction,
                            BlockCompletionFunc *complete)
 {
+    SCSIDevice *s = r->req.dev;
+
     r->io_header.interface_id = 'S';
     r->io_header.dxfer_direction = direction;
     r->io_header.dxferp = r->buf;
@@ -122,7 +124,7 @@ static int execute_command(BlockBackend *blk,
     r->io_header.cmd_len = r->req.cmd.len;
     r->io_header.mx_sb_len = sizeof(r->req.sense);
     r->io_header.sbp = r->req.sense;
-    r->io_header.timeout = MAX_UINT;
+    r->io_header.timeout = s->io_timeout * 1000;
     r->io_header.usr_ptr = r;
     r->io_header.flags |= SG_FLAG_DIRECT_IO;
 
@@ -505,7 +507,7 @@ static int read_naa_id(const uint8_t *p, uint64_t *p_wwn)
 }
 
 int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
-                        uint8_t *buf, uint8_t buf_size)
+                        uint8_t *buf, uint8_t buf_size, uint32_t timeout)
 {
     sg_io_hdr_t io_header;
     uint8_t sensebuf[8];
@@ -520,7 +522,7 @@ int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
     io_header.cmd_len = cmd_size;
     io_header.mx_sb_len = sizeof(sensebuf);
     io_header.sbp = sensebuf;
-    io_header.timeout = 6000; /* XXX */
+    io_header.timeout = timeout * 1000;
 
     ret = blk_ioctl(blk, SG_IO, &io_header);
     if (ret < 0 || io_header.driver_status || io_header.host_status) {
@@ -550,7 +552,7 @@ static void scsi_generic_set_vpd_bl_emulation(SCSIDevice *s)
     cmd[4] = sizeof(buf);
 
     ret = scsi_SG_IO_FROM_DEV(s->conf.blk, cmd, sizeof(cmd),
-                              buf, sizeof(buf));
+                              buf, sizeof(buf), s->io_timeout);
     if (ret < 0) {
         /*
          * Do not assume anything if we can't retrieve the
@@ -586,7 +588,7 @@ static void scsi_generic_read_device_identification(SCSIDevice *s)
     cmd[4] = sizeof(buf);
 
     ret = scsi_SG_IO_FROM_DEV(s->conf.blk, cmd, sizeof(cmd),
-                              buf, sizeof(buf));
+                              buf, sizeof(buf), s->io_timeout);
     if (ret < 0) {
         return;
     }
@@ -637,7 +639,7 @@ static int get_stream_blocksize(BlockBackend *blk)
     cmd[0] = MODE_SENSE;
     cmd[4] = sizeof(buf);
 
-    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf));
+    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf), 6);
     if (ret < 0) {
         return -1;
     }
@@ -727,6 +729,7 @@ static void scsi_generic_realize(SCSIDevice *s, Error **errp)
 
     /* Only used by scsi-block, but initialize it nevertheless to be clean.  */
     s->default_scsi_version = -1;
+    s->io_timeout = DEFAULT_IO_TIMEOUT;
     scsi_generic_read_device_inquiry(s);
 }
 
@@ -750,6 +753,8 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun,
 static Property scsi_generic_properties[] = {
     DEFINE_PROP_DRIVE("drive", SCSIDevice, conf.blk),
     DEFINE_PROP_BOOL("share-rw", SCSIDevice, conf.share_rw, false),
+    DEFINE_PROP_UINT32("io_timeout", SCSIDevice, io_timeout,
+                       DEFAULT_IO_TIMEOUT),
     DEFINE_PROP_END_OF_LIST(),
 };
 
diff --git a/include/hw/scsi/scsi.h b/include/hw/scsi/scsi.h
index 7a55cdbd74..21a6249743 100644
--- a/include/hw/scsi/scsi.h
+++ b/include/hw/scsi/scsi.h
@@ -18,6 +18,7 @@ typedef struct SCSIReqOps SCSIReqOps;
 
 #define SCSI_SENSE_BUF_SIZE_OLD 96
 #define SCSI_SENSE_BUF_SIZE 252
+#define DEFAULT_IO_TIMEOUT 30
 
 struct SCSIRequest {
     SCSIBus           *bus;
@@ -84,6 +85,7 @@ struct SCSIDevice
     uint64_t port_wwn;
     int scsi_version;
     int default_scsi_version;
+    uint32_t io_timeout;
     bool needs_vpd_bl_emulation;
     bool hba_supports_iothread;
 };
@@ -188,7 +190,7 @@ void scsi_device_unit_attention_reported(SCSIDevice *dev);
 void scsi_generic_read_device_inquiry(SCSIDevice *dev);
 int scsi_device_get_sense(SCSIDevice *dev, uint8_t *buf, int len, bool fixed);
 int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
-                        uint8_t *buf, uint8_t buf_size);
+                        uint8_t *buf, uint8_t buf_size, uint32_t timeout);
 SCSIDevice *scsi_device_find(SCSIBus *bus, int channel, int target, int lun);
 
 /* scsi-generic.c. */
-- 
2.16.4

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Paolo Bonzini]

On Mon, Nov 16, 2020 at 7:31 PM Hannes Reinecke <hare@suse.de> wrote:
> The current code sets an infinite timeout on SG_IO requests,
> causing the guest to stall if the host experiences a frame
> loss.
> This patch adds an 'io_timeout' parameter for SCSIDevice to
> make the SG_IO timeout configurable, and also shortens the
> default timeout to 30 seconds to avoid infinite stalls.

Hannes, could 30 seconds be a bit too short for tape drives?

Paolo

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Hannes Reinecke]

On 9/20/21 8:56 PM, Paolo Bonzini wrote:
> On Mon, Nov 16, 2020 at 7:31 PM Hannes Reinecke <hare@suse.de> wrote:
>> The current code sets an infinite timeout on SG_IO requests,
>> causing the guest to stall if the host experiences a frame
>> loss.
>> This patch adds an 'io_timeout' parameter for SCSIDevice to
>> make the SG_IO timeout configurable, and also shortens the
>> default timeout to 30 seconds to avoid infinite stalls.
> 
> Hannes, could 30 seconds be a bit too short for tape drives?
> 
It would, but then anyone attempting to use tapes via qemu emulation 
deserves to suffer.
Tapes are bitchy even when used normally, so attempting to use them 
under qemu emulation will land you with lots of unhappy experiences, 
where the timeout is the least of your problems.
I sincerely doubt anyone will be using tapes here.
Not in real-world scenarios.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke                Kernel Storage Architect
hare@suse.de                              +49 911 74053 688
SUSE Software Solutions GmbH, Maxfeldstr. 5, 90409 Nürnberg
HRB 36809 (AG Nürnberg), Geschäftsführer: Felix Imendörffer

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Paolo Bonzini]

On 21/09/21 07:39, Hannes Reinecke wrote:
> It would, but then anyone attempting to use tapes via qemu emulation 
> deserves to suffer.
> Tapes are bitchy even when used normally, so attempting to use them 
> under qemu emulation will land you with lots of unhappy experiences, 
> where the timeout is the least of your problems.
> I sincerely doubt anyone will be using tapes here.
> Not in real-world scenarios.

Hmm, I have customers that disagree.  Probably the timeout should be 
kept infinite for tapes.

Paolo

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Philippe Mathieu-Daudé]

Hi Hannes,

On 11/16/20 19:31, Hannes Reinecke wrote:
> The current code sets an infinite timeout on SG_IO requests,
> causing the guest to stall if the host experiences a frame
> loss.
> This patch adds an 'io_timeout' parameter for SCSIDevice to
> make the SG_IO timeout configurable, and also shortens the
> default timeout to 30 seconds to avoid infinite stalls.
> 
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>   hw/scsi/scsi-disk.c    |  6 ++++--
>   hw/scsi/scsi-generic.c | 17 +++++++++++------
>   include/hw/scsi/scsi.h |  4 +++-
>   3 files changed, 18 insertions(+), 9 deletions(-)

>   int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
> -                        uint8_t *buf, uint8_t buf_size)
> +                        uint8_t *buf, uint8_t buf_size, uint32_t timeout)
>   {
>       sg_io_hdr_t io_header;
>       uint8_t sensebuf[8];
> @@ -520,7 +522,7 @@ int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
>       io_header.cmd_len = cmd_size;
>       io_header.mx_sb_len = sizeof(sensebuf);
>       io_header.sbp = sensebuf;
> -    io_header.timeout = 6000; /* XXX */
> +    io_header.timeout = timeout * 1000;

> @@ -637,7 +639,7 @@ static int get_stream_blocksize(BlockBackend *blk)
>       cmd[0] = MODE_SENSE;
>       cmd[4] = sizeof(buf);
>   
> -    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf));
> +    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf), 6);

Why is this timeout hardcoded? Due to the /* XXX */ comment?

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Hannes Reinecke]

On 9/22/21 5:47 PM, Philippe Mathieu-Daudé wrote:
> Hi Hannes,
> 
> On 11/16/20 19:31, Hannes Reinecke wrote:
>> The current code sets an infinite timeout on SG_IO requests,
>> causing the guest to stall if the host experiences a frame
>> loss.
>> This patch adds an 'io_timeout' parameter for SCSIDevice to
>> make the SG_IO timeout configurable, and also shortens the
>> default timeout to 30 seconds to avoid infinite stalls.
>>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>   hw/scsi/scsi-disk.c    |  6 ++++--
>>   hw/scsi/scsi-generic.c | 17 +++++++++++------
>>   include/hw/scsi/scsi.h |  4 +++-
>>   3 files changed, 18 insertions(+), 9 deletions(-)
> 
>>   int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t 
>> cmd_size,
>> -                        uint8_t *buf, uint8_t buf_size)
>> +                        uint8_t *buf, uint8_t buf_size, uint32_t 
>> timeout)
>>   {
>>       sg_io_hdr_t io_header;
>>       uint8_t sensebuf[8];
>> @@ -520,7 +522,7 @@ int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t 
>> *cmd, uint8_t cmd_size,
>>       io_header.cmd_len = cmd_size;
>>       io_header.mx_sb_len = sizeof(sensebuf);
>>       io_header.sbp = sensebuf;
>> -    io_header.timeout = 6000; /* XXX */
>> +    io_header.timeout = timeout * 1000;
> 
>> @@ -637,7 +639,7 @@ static int get_stream_blocksize(BlockBackend *blk)
>>       cmd[0] = MODE_SENSE;
>>       cmd[4] = sizeof(buf);
>> -    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf));
>> +    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, 
>> sizeof(buf), 6);
> 
> Why is this timeout hardcoded? Due to the /* XXX */ comment?
> 

60 seconds is the default command timeout on linux.
And the problem is that the guest might set a command timeout on the 
comands being send from the guests user space, but the guest is unable
to communicate this timeout to the host.

Really, one should fix up the virtio spec here to allow for a 'timeout' 
field. But in the absence of that being able to configure it is the next 
best attempt.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke                Kernel Storage Architect
hare@suse.de                              +49 911 74053 688
SUSE Software Solutions GmbH, Maxfeldstr. 5, 90409 Nürnberg
HRB 36809 (AG Nürnberg), Geschäftsführer: Felix Imendörffer

Re: [PATCH 2/3] scsi: make io_timeout configurable

[Paolo Bonzini]

On 22/09/21 17:47, Philippe Mathieu-Daudé wrote:
>>
> 
>> @@ -637,7 +639,7 @@ static int get_stream_blocksize(BlockBackend *blk)
>>       cmd[0] = MODE_SENSE;
>>       cmd[4] = sizeof(buf);
>> -    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, sizeof(buf));
>> +    ret = scsi_SG_IO_FROM_DEV(blk, cmd, sizeof(cmd), buf, 
>> sizeof(buf), 6);
> 
> Why is this timeout hardcoded? Due to the /* XXX */ comment?

This command is only invoked at startup and involves no I/O, so 6 
seconds should be plenty.

Paolo

[PATCH 3/3] scsi: add tracing for SG_IO commands

[Hannes Reinecke]

Add tracepoints for SG_IO commands to allow for debugging
of SG_IO commands.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 hw/scsi/scsi-disk.c    | 3 ++-
 hw/scsi/scsi-generic.c | 8 +++++++-
 hw/scsi/trace-events   | 4 ++++
 3 files changed, 13 insertions(+), 2 deletions(-)

diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c
index 2959526b52..dd23a38d6a 100644
--- a/hw/scsi/scsi-disk.c
+++ b/hw/scsi/scsi-disk.c
@@ -2768,7 +2768,8 @@ static BlockAIOCB *scsi_block_do_sgio(SCSIBlockReq *req,
     io_header->timeout = s->qdev.io_timeout * 1000;
     io_header->usr_ptr = r;
     io_header->flags |= SG_FLAG_DIRECT_IO;
-
+    trace_scsi_disk_aio_sgio_command(r->req.tag, req->cdb[0], lba,
+                                     nb_logical_blocks, io_header->timeout);
     aiocb = blk_aio_ioctl(s->qdev.conf.blk, SG_IO, io_header, cb, opaque);
     assert(aiocb != NULL);
     return aiocb;
diff --git a/hw/scsi/scsi-generic.c b/hw/scsi/scsi-generic.c
index e07924b3d7..8687336438 100644
--- a/hw/scsi/scsi-generic.c
+++ b/hw/scsi/scsi-generic.c
@@ -128,6 +128,8 @@ static int execute_command(BlockBackend *blk,
     r->io_header.usr_ptr = r;
     r->io_header.flags |= SG_FLAG_DIRECT_IO;
 
+    trace_scsi_generic_aio_sgio_command(r->req.tag, r->req.cmd.buf[0],
+                                        r->io_header.timeout);
     r->req.aiocb = blk_aio_ioctl(blk, SG_IO, &r->io_header, complete, r);
     if (r->req.aiocb == NULL) {
         return -EIO;
@@ -524,8 +526,12 @@ int scsi_SG_IO_FROM_DEV(BlockBackend *blk, uint8_t *cmd, uint8_t cmd_size,
     io_header.sbp = sensebuf;
     io_header.timeout = timeout * 1000;
 
+    trace_scsi_generic_ioctl_sgio_command(cmd[0], io_header.timeout);
     ret = blk_ioctl(blk, SG_IO, &io_header);
-    if (ret < 0 || io_header.driver_status || io_header.host_status) {
+    if (ret < 0 || io_header.status ||
+        io_header.driver_status || io_header.host_status) {
+        trace_scsi_generic_ioctl_sgio_done(cmd[0], ret, io_header.status,
+                                           io_header.host_status);
         return -1;
     }
     return 0;
diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index 0e0aa9847d..9788661bfd 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -331,6 +331,7 @@ scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI comma
 scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)"
 scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)"
 scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s"
+scsi_disk_aio_sgio_command(uint32_t tag, uint8_t cmd, uint64_t lba, int len, uint32_t timeout) "disk aio sgio: tag=0x%x cmd=0x%x (sector %" PRId64 ", count %d) timeout=%u"
 
 # scsi-generic.c
 scsi_generic_command_complete_noio(void *req, uint32_t tag, int statuc) "Command complete %p tag=0x%x status=%d"
@@ -342,3 +343,6 @@ scsi_generic_write_data(uint32_t tag) "scsi_write_data tag=0x%x"
 scsi_generic_send_command(const char *line) "Command: data=%s"
 scsi_generic_realize_type(int type) "device type %d"
 scsi_generic_realize_blocksize(int blocksize) "block size %d"
+scsi_generic_aio_sgio_command(uint32_t tag, uint8_t cmd, uint32_t timeout) "generic aio sgio: tag=0x%x cmd=0x%x timeout=%u"
+scsi_generic_ioctl_sgio_command(uint8_t cmd, uint32_t timeout) "generic ioctl sgio: cmd=0x%x timeout=%u"
+scsi_generic_ioctl_sgio_done(uint8_t cmd, int ret, uint8_t status, uint8_t host_status) "generic ioctl sgio: cmd=0x%x ret=%d status=0x%x host_status=0x%x"
-- 
2.16.4

Re: [PATCH 0/3] scsi: infinite guest hangs with scsi-disk

[no-reply]

Patchew URL: https://patchew.org/QEMU/20201116183114.55703-1-hare@suse.de/



Hi,

This series seems to have some coding style problems. See output below for
more information:

Message-id: 20201116183114.55703-1-hare@suse.de
Type: series
Subject: [PATCH 0/3] scsi: infinite guest hangs with scsi-disk

=== TEST SCRIPT BEGIN ===
#!/bin/bash
git rev-parse base > /dev/null || exit 0
git config --local diff.renamelimit 0
git config --local diff.renames True
git config --local diff.algorithm histogram
./scripts/checkpatch.pl --mailback base..
=== TEST SCRIPT END ===

Updating 3c8cf5a9c21ff8782164d1def7f44bd888713384
From https://github.com/patchew-project/qemu
 - [tag update]      patchew/20201116104617.18333-1-peter.maydell@linaro.org -> patchew/20201116104617.18333-1-peter.maydell@linaro.org
 - [tag update]      patchew/20201116165506.31315-1-eperezma@redhat.com -> patchew/20201116165506.31315-1-eperezma@redhat.com
 * [new tag]         patchew/20201116183114.55703-1-hare@suse.de -> patchew/20201116183114.55703-1-hare@suse.de
Switched to a new branch 'test'
350bcf1 scsi: add tracing for SG_IO commands
7ecf5b6 scsi: make io_timeout configurable
450c008 virtio-scsi: trace events

=== OUTPUT BEGIN ===
1/3 Checking commit 450c008843e5 (virtio-scsi: trace events)
ERROR: trailing whitespace
#116: FILE: hw/scsi/virtio-scsi.c:797:
+     $

total: 1 errors, 0 warnings, 92 lines checked

Patch 1/3 has style problems, please review.  If any of these errors
are false positives report them to the maintainer, see
CHECKPATCH in MAINTAINERS.

2/3 Checking commit 7ecf5b611a5b (scsi: make io_timeout configurable)
3/3 Checking commit 350bcf121178 (scsi: add tracing for SG_IO commands)
=== OUTPUT END ===

Test command exited with code: 1


The full log is available at
http://patchew.org/logs/20201116183114.55703-1-hare@suse.de/testing.checkpatch/?type=message.
---
Email generated automatically by Patchew [https://patchew.org/].
Please send your feedback to patchew-devel@redhat.com

Re: [PATCH 0/3] scsi: infinite guest hangs with scsi-disk

[Paolo Bonzini]

On 16/11/20 19:31, Hannes Reinecke wrote:
> Hi all,
> 
> one of our customers reported an infinite guest hang following an FC link loss  when using scsi-disk.
> Problem is that scsi-disk issues SG_IO command with a timeout of UINT_MAX, which essentially signals
> 'no timeout' to the host kernel. So if the command gets lost eg during an unexpected link loss the
> HBA driver will never attempt to abort or return the command. Hence the guest will hang forever, and
> the only way to resolve things is to reboot the host.
> 
> To solve it this patchset adds an 'io_timeout' parameter to scsi-disk and scsi-generic, which allows
> the admin to specify a command timeout for SG_IO request. It is initialized to 30 seconds to avoid the
> infinite hang as mentioned above.
> 
> As usual, comments and reviews are welcome.
> 
> Hannes Reinecke (3):
>    virtio-scsi: trace events
>    scsi: make io_timeout configurable
>    scsi: add tracing for SG_IO commands
> 
>   hw/scsi/scsi-disk.c    |  9 ++++++---
>   hw/scsi/scsi-generic.c | 25 ++++++++++++++++++-------
>   hw/scsi/trace-events   | 13 +++++++++++++
>   hw/scsi/virtio-scsi.c  | 30 +++++++++++++++++++++++++++++-
>   include/hw/scsi/scsi.h |  4 +++-
>   5 files changed, 69 insertions(+), 12 deletions(-)
> 

The UINT_MAX timeout predates me, but I think the idea was to make it 
sort of like NFS's hard option.  Without a timeout you cannot be quite 
sure if/when the command will stay in some buffer of the HBA or the SAN 
or the target, and there could be unintended reordering of writes.

Though I guess at some point you'll anyway restart the VM on another 
host and the same reordering can happen, so I've queued the patch.

Paolo