Comment 8 for bug 1798110

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