Re: iotest 040, 041, intermittent failure in netbsd VM

[John Snow <jsnow@redhat.com>]

On Mon, Jan 17, 2022 at 3:49 PM Peter Maydell <peter.maydell@linaro.org> wrote:
>
> On Mon, 17 Jan 2022 at 20:35, John Snow <jsnow@redhat.com> wrote:
>
> > Can you please try applying this temporary patch and running `./check
> > -qcow2 040 041` until you see a breakage and show me the output from
> > that?
>
> With this temporary patch the VM doesn't launch at all:

"Works for me", but I found out why.

>
> peter.maydell@hackbox2.linaro.org:~/qemu-netbsd$ make -C build/
> vm-build-netbsd J=8 V=1 2>&1 | tee netbsd.log
> make: Entering directory '/home/peter.maydell/qemu-netbsd/build'
> /usr/bin/python3 -B /home/peter.maydell/qemu-netbsd/meson/meson.py
> introspect --targets --tests --benchmarks | /usr/bin/python3 -B
> scripts/mtest2m
> ake.py > Makefile.mtest
> { \
>   echo 'ninja-targets = \'; \
>   /usr/bin/ninja -t targets all | sed 's/:.*//; $!s/$/ \\/'; \
>   echo 'build-files = \'; \
>   /usr/bin/ninja -t query build.ninja | sed -n '1,/^  input:/d; /^
> outputs:/q; s/$/ \\/p'; \
> } > Makefile.ninja.tmp && mv Makefile.ninja.tmp Makefile.ninja
> (GIT="git" "/home/peter.maydell/qemu-netbsd/scripts/git-submodule.sh"
> update ui/keycodemapdb meson tests/fp/berkeley-testfloat-3
> tests/fp/berkeley-softfloat-3 dtc capstone slirp)
> (GIT="git" "/home/peter.maydell/qemu-netbsd/scripts/git-submodule.sh"
> update ui/keycodemapdb meson tests/fp/berkeley-testfloat-3
> tests/fp/berkeley-softfloat-3 dtc capstone slirp)
> /usr/bin/python3 -B /home/peter.maydell/qemu-netbsd/tests/vm/netbsd
> --debug  --jobs 8 --verbose    --image
> "/home/peter.maydell/.cache/qemu-vm/images/netbsd.img"  --snapshot
> --build-qemu /home/peter.maydell/qemu-netbsd --
> DEBUG:root:Creating archive
> /home/peter.maydell/qemu-netbsd/build/vm-test-72ra6_8s.tmp/data-f706c.tar
> for src_dir dir: /home/peter.maydell/qemu-netbsd
> DEBUG:root:QEMU args: -nodefaults -m 4G -cpu max -netdev
> user,id=vnet,hostfwd=:127.0.0.1:0-:22,ipv6=no -device
> virtio-net-pci,netdev=vnet -vnc 127.0.0.1:0,to=20 -smp 8 -enable-kvm
> -drive file=/home/peter.maydell/.cache/qemu-vm/images/netbsd.img,snapshot=on,if=none,id=drive0,cache=writeback
> -device virtio-blk,drive=drive0,bootindex=0 -drive
> file=/home/peter.maydell/qemu-netbsd/build/vm-test-72ra6_8s.tmp/data-f706c.tar,if=none,id=data-f706c,cache=writeback,format=raw
> -device virtio-blk,drive=data-f706c,serial=data-f706c,bootindex=1
> DEBUG:asyncio:Using selector: EpollSelector
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Registering
> <qemu.aqmp.events.EventListener object at 0x7f3b76bfc9b0>.
> DEBUG:qemu.machine.machine:VM launch command: 'qemu-system-x86_64
> -display none -vga none -chardev
> socket,id=mon,path=/var/tmp/qemu-machine-0m15ou19/qemu-2335-7f3b78d7f128-monitor.sock
> -mon chardev=mon,mode=control -machine pc -chardev
> socket,id=console,path=/var/tmp/qemu-machine-0m15ou19/qemu-2335-7f3b78d7f128-console.sock,server=on,wait=off
> -serial chardev:console -nodefaults -m 4G -cpu max -netdev
> user,id=vnet,hostfwd=:127.0.0.1:0-:22,ipv6=no -device
> virtio-net-pci,netdev=vnet -vnc 127.0.0.1:0,to=20 -smp 8 -enable-kvm
> -drive file=/home/peter.maydell/.cache/qemu-vm/images/netbsd.img,snapshot=on,if=none,id=drive0,cache=writeback
> -device virtio-blk,drive=drive0,bootindex=0 -drive
> file=/home/peter.maydell/qemu-netbsd/build/vm-test-72ra6_8s.tmp/data-f706c.tar,if=none,id=data-f706c,cache=writeback,format=raw
> -device virtio-blk,drive=data-f706c,serial=data-f706c,bootindex=1'
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Transitioning from
> 'Runstate.IDLE' to 'Runstate.CONNECTING'.
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Awaiting connection
> on /var/tmp/qemu-machine-0m15ou19/qemu-2335-7f3b78d7f128-monitor.sock
> ...
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Connection accepted.
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Awaiting greeting ...
> DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:<-- {
>   "QMP": {
>     "version": {
>       "qemu": {
>         "micro": 1,
>         "minor": 11,
>         "major": 2
>       },
>       "package": "(Debian 1:2.11+dfsg-1ubuntu7.38)"
>     },
>     "capabilities": []
>   }
> }

Well, today I learned that:

(1) vm-build-XXX targets use your host system's QEMU to run that VM
(2) my QMP library cannot talk to QEMU 2.11.

That doesn't explain the intermittent netbsd failure yet, though.
(I guess this wasn't a failure point for you due to the aggressive
caching of the VM images? Unlucky.)

Here's another hotfix, this one I cannot easily test quickly (I don't
have 2.11 handy and it no longer builds for me),
but I think it'll fix the VM installation problem against older QEMU versions:

diff --git a/python/qemu/aqmp/qmp_client.py b/python/qemu/aqmp/qmp_client.py
index 8105e29fa8..6b43e1dbbe 100644
--- a/python/qemu/aqmp/qmp_client.py
+++ b/python/qemu/aqmp/qmp_client.py
@@ -292,9 +292,9 @@ async def _negotiate(self) -> None:
         """
         self.logger.debug("Negotiating capabilities ...")

-        arguments: Dict[str, List[str]] = {'enable': []}
+        arguments: Dict[str, List[str]] = {}
         if self._greeting and 'oob' in self._greeting.QMP.capabilities:
-            arguments['enable'].append('oob')
+            arguments.setdefault('enable', []).append('oob')
         msg = self.make_execute_msg('qmp_capabilities', arguments=arguments)

         # It's not safe to use execute() here, because the reader/writers