Verification successful with the kernel in xenial-proposed.
Updating verification tags.

Details
=======

Guest:
---

root@mfo-sf194614:~# apt-cache madison linux-image-4.4.0-139-generic
linux-image-4.4.0-139-generic | 4.4.0-139.165 | http://archive.ubuntu.com/ubuntu/ xenial-proposed/main amd64 Packages

root@mfo-sf194614:~# apt-get -y install linux-image-4.4.0-139-generic
root@mfo-sf194614:~# reboot

root@mfo-sf194614:~# uname -a
Linux mfo-sf194614 4.4.0-139-generic #165-Ubuntu SMP Wed Oct 24 10:58:50 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

root@mfo-sf194614:~# ls -ld /sys/block/sda
lrwxrwxrwx 1 root root 0 Oct 25 13:51 /sys/block/sda -> ../devices/pci0000:00/0000:00:07.0/virtio4/host2/target2:0:0/2:0:0:0/block/sda

root@mfo-sf194614:~# lspci -s 7.0
00:07.0 SCSI storage controller: Red Hat, Inc Virtio SCSI

root@mfo-sf194614:~# echo 9 > /proc/sys/kernel/printk
root@mfo-sf194614:~# scsi_logging_level --set --mlqueue=4 --mlcomplete=2

root@mfo-sf194614:~# dd if=/dev/sda of=/dev/null count=1
[  139.412030] sd 2:0:0:0: [sda] tag#1 Send: scmd 0xffff880036e614f0
[  139.415541] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
[  139.418561] sd 2:0:0:0: [sda] tag#1 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  139.421753] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00

[  139.424561] sd 2:0:0:0: tag#1 Send: scmd 0xffff880036e614f0
[  139.427081] sd 2:0:0:0: tag#1 CDB: Test Unit Ready 00 00 00 00 00 00
[  139.428997] sd 2:0:0:0: tag#1 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  139.430982] sd 2:0:0:0: tag#1 CDB: Test Unit Ready 00 00 00 00 00 00

root@mfo-sf194614:~# cat /sys/module/virtio_scsi/sections/.text
0xffffffffc0002000

Host:
---

mfo@rotom:~/ddebs$ vscsi_text='0xffffffffc0002000'
mfo@rotom:~/ddebs$ virsh qemu-monitor-command mfo-sf194614 --hmp 'gdbserver'

mfo@rotom:~/ddebs$ wget http://ddebs.ubuntu.com/pool/main/l/linux/linux-image-4.4.0-139-generic-dbgsym_4.4.0-139.165_amd64.ddeb
mfo@rotom:~/ddebs$ dpkg-deb -x linux-image-4.4.0-139-generic-dbgsym_4.4.0-139.165_amd64.ddeb linux-image-4.4.0-139-generic-dbgsym_4.4.0-139.165_amd64/
mfo@rotom:~/ddebs$ cd linux-image-4.4.0-139-generic-dbgsym_4.4.0-139.165_amd64/usr/lib/debug/

gdb boot/vmlinux-4.4.0-139-generic \
  -ex 'set confirm off' \
  -ex "add-symbol-file lib/modules/4.4.0-139-generic/kernel/drivers/scsi/virtio_scsi.ko $vscsi_text" \
  -ex 'break virtscsi_queuecommand' \
  -ex 'target remote localhost:1234' \
  -ex 'continue'

Guest
---

root@mfo-sf194614:~# dd if=/dev/sda of=/dev/null count=1 2>/dev/null
[  435.462432] sd 2:0:0:0: [sda] tag#1 Send: scmd 0xffff880036e614f0
[  435.465679] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
<freeze>


Host GDB:
---

Thread 2 hit Breakpoint 1, virtscsi_queuecommand (vscsi=0xffff88013a6cf7d8, req_vq=0xffff88013a6cf9e8, sc=0xffff880036e614f0)
    at /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c:534
534     /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c: No such file or directory.
(gdb) break virtio_ring.c:196
Breakpoint 2 at 0xffffffff814e383f: virtio_ring.c:196. (3 locations)
(gdb) info break
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   0xffffffffc0003330 in virtscsi_queuecommand 
                                                   at /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c:534
        breakpoint already hit 1 time
2       breakpoint     keep y   <MULTIPLE>         
2.1                         y     0xffffffff814e383f in virtqueue_add_sgs 
                                                   at /build/linux-PrHwV2/linux-4.4.0/drivers/virtio/virtio_ring.c:196
2.2                         y     0xffffffff814e3dec in virtqueue_add_inbuf 
                                                   at /build/linux-PrHwV2/linux-4.4.0/drivers/virtio/virtio_ring.c:196
2.3                         y     0xffffffff814e409c in virtqueue_add_outbuf 
                                                   at /build/linux-PrHwV2/linux-4.4.0/drivers/virtio/virtio_ring.c:196
(gdb) disable 1
(gdb) disable 2.2
(gdb) disable 2.3
(gdb) continue
Continuing.

Thread 2 hit Breakpoint 2, virtqueue_add (gfp=<optimized out>, data=<optimized out>, in_sgs=<optimized out>, out_sgs=<optimized out>, 
    total_sg=<optimized out>, sgs=<optimized out>, _vq=<optimized out>) at /build/linux-PrHwV2/linux-4.4.0/drivers/virtio/virtio_ring.c:197
197     /build/linux-PrHwV2/linux-4.4.0/drivers/virtio/virtio_ring.c: No such file or directory.
(gdb) disass
Dump of assembler code for function virtqueue_add_sgs:
...
=> 0xffffffff814e383f <+175>:   cmp    %ecx,%ebx
   0xffffffff814e3841 <+177>:   ja     0xffffffff814e3a15 <virtqueue_add_sgs+645>
...

(gdb) info reg $ecx $ebx
ecx            0x80     128
ebx            0x1      1

(gdb) set $ecx = 0

(gdb) info reg $ecx $ebx
ecx            0x0      0
ebx            0x1      1

(gdb) disable 2.1
(gdb) break virtscsi_target_destroy
Breakpoint 3 at 0xffffffffc0002020: file /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c, line 791.

(gdb) continue
Continuing.


Guest
---

root@mfo-sf194614:~# dd if=/dev/sda of=/dev/null count=1 2>/dev/null
[  435.462432] sd 2:0:0:0: [sda] tag#1 Send: scmd 0xffff880036e614f0
[  435.465679] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
<freeze>
<continued after GDB above>
[  435.474443] sd 2:0:0:0: [sda] tag#1 queuecommand : request rejected
[  435.504597] scsi host2: unblocking host at zero depth

[  435.507603] sd 2:0:0:0: [sda] tag#1 Send: scmd 0xffff880036e614f0
[  435.510896] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
[  435.515713] sd 2:0:0:0: [sda] tag#1 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  435.520838] sd 2:0:0:0: [sda] tag#1 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00

[  435.525044] sd 2:0:0:0: tag#1 Send: scmd 0xffff880036e614f0
[  435.527795] sd 2:0:0:0: tag#1 CDB: Test Unit Ready 00 00 00 00 00 00
[  435.553066] sd 2:0:0:0: tag#1 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  435.555822] sd 2:0:0:0: tag#1 CDB: Test Unit Ready 00 00 00 00 00 00


Host
---

mfo@rotom:~$ virsh qemu-monitor-command mfo-sf194614 --hmp 'device_del scsi1-0-0-0'


Guest
---

[  549.088876] sd 2:0:0:0: [sda] Synchronizing SCSI cache
<...>
[  549.152828] sd 2:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK


Host GDB
---

Thread 1 hit Breakpoint 3, virtscsi_target_destroy (starget=0xffff880036c62800)
    at /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c:791
791     /build/linux-PrHwV2/linux-4.4.0/drivers/scsi/virtio_scsi.c: No such file or directory.
(gdb) disass
Dump of assembler code for function virtscsi_target_destroy:
=> 0xffffffffc0002020 <+0>:     nopl   0x0(%rax,%rax,1)
   0xffffffffc0002025 <+5>:     push   %rbp
   0xffffffffc0002026 <+6>:     mov    0x328(%rdi),%rdi
   0xffffffffc000202d <+13>:    mov    %rsp,%rbp
   0xffffffffc0002030 <+16>:    mov    0x4(%rdi),%eax
   0xffffffffc0002033 <+19>:    test   %eax,%eax
   0xffffffffc0002035 <+21>:    je     0xffffffffc0002040 <virtscsi_target_destroy+32>
   0xffffffffc0002037 <+23>:    pause  
   0xffffffffc0002039 <+25>:    mov    0x4(%rdi),%eax
   0xffffffffc000203c <+28>:    test   %eax,%eax
   0xffffffffc000203e <+30>:    jne    0xffffffffc0002037 <virtscsi_target_destroy+23>
   0xffffffffc0002040 <+32>:    callq  0xffffffff811f64a0 <kfree>
   0xffffffffc0002045 <+37>:    pop    %rbp
   0xffffffffc0002046 <+38>:    retq   
End of assembler dump.
(gdb) si
(gdb) 
(gdb) 
(gdb) 
(gdb) 
(gdb) disass
Dump of assembler code for function virtscsi_target_destroy:
   0xffffffffc0002020 <+0>:     nopl   0x0(%rax,%rax,1)
   0xffffffffc0002025 <+5>:     push   %rbp
   0xffffffffc0002026 <+6>:     mov    0x328(%rdi),%rdi
   0xffffffffc000202d <+13>:    mov    %rsp,%rbp
   0xffffffffc0002030 <+16>:    mov    0x4(%rdi),%eax
=> 0xffffffffc0002033 <+19>:    test   %eax,%eax
   0xffffffffc0002035 <+21>:    je     0xffffffffc0002040 <virtscsi_target_destroy+32>
   0xffffffffc0002037 <+23>:    pause  
   0xffffffffc0002039 <+25>:    mov    0x4(%rdi),%eax
   0xffffffffc000203c <+28>:    test   %eax,%eax
   0xffffffffc000203e <+30>:    jne    0xffffffffc0002037 <virtscsi_target_destroy+23>
   0xffffffffc0002040 <+32>:    callq  0xffffffff811f64a0 <kfree>
   0xffffffffc0002045 <+37>:    pop    %rbp
   0xffffffffc0002046 <+38>:    retq   
End of assembler dump.

(gdb) info reg $eax
eax            0x0      0

That looks good! :-)

(gdb) continue


Host
---

And indeed, the CPU usage for the QEMU process remains low.  Problem resolved.


mfo@rotom:~$ pid=$(ps ax | grep qemu | grep mfo-sf194614 | cut -d' ' -f1)
mfo@rotom:~$ top -b -d 1 -n 10 -p $pid | grep qemu
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.98 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   1.0  0.6   1:05.99 qemu-system-x86
10234 libvirt+  20   0 9016056 768008  23260 S   0.0  0.6   1:05.99 qemu-system-x86