Re: iotest 040, 041, intermittent failure in netbsd VM
On Tue, Jan 18, 2022 at 1:34 PM John Snow wrote: > > On Tue, Jan 18, 2022 at 7:13 AM Peter Maydell > wrote: > > > > On Mon, 17 Jan 2022 at 20:35, John Snow wrote: > > > I do expect this to print more information on failure than it > > > currently is, though (bug somewhere in machine.py, I think). > > > 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? > > > > Thanks for playing tele-debug. > > > Having fixed my setup to not use an ancient host QEMU, here's > > the relevant bit of the log: > > > > TEST iotest-qcow2: 037 > > TEST iotest-qcow2: 038 [not run] > > TEST iotest-qcow2: 039 [not run] > > TEST iotest-qcow2: 040 [fail] > > QEMU -- > > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64" > > -nodefaults -display none -accel qtest -machine virt > > QEMU_IMG -- > > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-img" > > QEMU_IO -- > > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-io" > > --cache writeback --aio threads -f qcow2 > > QEMU_NBD -- > > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-nbd" > > IMGFMT-- qcow2 > > IMGPROTO -- file > > PLATFORM -- NetBSD/amd64 localhost 9.2 > > TEST_DIR -- > > /home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch > > SOCK_DIR -- /tmp/tmp1h12r7ev > > GDB_OPTIONS -- > > VALGRIND_QEMU -- > > PRINT_QEMU_OUTPUT -- > > > > --- /home/qemu/qemu-test.vdrI02/src/tests/qemu-iotests/040.out > > +++ 040.out.bad > > @@ -1,5 +1,95 @@ > > -. > > +...ERROR:qemu.aqmp.qmp_client.qemu-12407:Failed to establish > > connection: concurrent.futures._base.CancelledError > > +ERROR:qemu.machine.machine:Error launching VM > > +ERROR:qemu.machine.machine:Process was forked, waiting on it > > +ERROR:qemu.machine.machine:Command: > > '/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64 > > -display none -vga none -chardev > > socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock -mon > > chardev=mon,mode=control -qtest > > unix:path=/tmp/tmp1h12r7ev/qemu-12407-qtest.sock -accel qtest > > -nodefaults -display none -accel qtest -machine virt -drive > > if=none,id=drive0,file=/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,node-name=top,backing.node-name=mid,backing.backing.node-name=base > > -device virtio-scsi -device scsi-hd,id=scsi0,drive=drive0' > > > +ERROR:qemu.machine.machine:Output: "qemu-system-aarch64: -chardev > > socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock: Failed to > > connect to '/tmp/tmp1h12r7ev/qemu-12407-monitor.sock': No such file or > > directory\n" > > ... Oh. That's unpleasant. My guess is that we aren't listening on the > socket before the QEMU process gets far enough to want to connect to > it. The change to an asynchronous backend must have jostled the > timing. > > > +ERROR:qemu.machine.machine:exitcode: 1 > > And, oh: The VM launching library only chirps about *negative* error > codes. That's why it wasn't printing anything more useful. I suppose > the thinking was that we use the VM launch utility to knowingly launch > bad command lines, so we only wanted to see failure notifications on > -errno style codes, but that obviously makes debugging unintentional > failures a lot more awful. I'll try to improve the usability and > legibility of the errors here. > > Thanks, > --js I've published '[PATCH v2 0/5] Python: minor fixes' and pushed to jsnow/python. Test it if you want; otherwise I'll wait for reviews/acks and send a PR like normal. CI is still running on the final push, but early smoke tests looked good. (Patch 1 fixes compatibility with QEMU 2.11, patch 3 adds better diagnostic info to failures, patch 5 should ultimately fix the root cause of the race condition.) Thanks, --js
Re: iotest 040, 041, intermittent failure in netbsd VM
On Tue, Jan 18, 2022 at 7:13 AM Peter Maydell wrote: > > On Mon, 17 Jan 2022 at 20:35, John Snow wrote: > > I do expect this to print more information on failure than it > > currently is, though (bug somewhere in machine.py, I think). > > 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? > Thanks for playing tele-debug. > Having fixed my setup to not use an ancient host QEMU, here's > the relevant bit of the log: > > TEST iotest-qcow2: 037 > TEST iotest-qcow2: 038 [not run] > TEST iotest-qcow2: 039 [not run] > TEST iotest-qcow2: 040 [fail] > QEMU -- > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64" > -nodefaults -display none -accel qtest -machine virt > QEMU_IMG -- > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-img" > QEMU_IO -- > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-io" > --cache writeback --aio threads -f qcow2 > QEMU_NBD -- > "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-nbd" > IMGFMT-- qcow2 > IMGPROTO -- file > PLATFORM -- NetBSD/amd64 localhost 9.2 > TEST_DIR -- /home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch > SOCK_DIR -- /tmp/tmp1h12r7ev > GDB_OPTIONS -- > VALGRIND_QEMU -- > PRINT_QEMU_OUTPUT -- > > --- /home/qemu/qemu-test.vdrI02/src/tests/qemu-iotests/040.out > +++ 040.out.bad > @@ -1,5 +1,95 @@ > -. > +...ERROR:qemu.aqmp.qmp_client.qemu-12407:Failed to establish > connection: concurrent.futures._base.CancelledError > +ERROR:qemu.machine.machine:Error launching VM > +ERROR:qemu.machine.machine:Process was forked, waiting on it > +ERROR:qemu.machine.machine:Command: > '/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64 > -display none -vga none -chardev > socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock -mon > chardev=mon,mode=control -qtest > unix:path=/tmp/tmp1h12r7ev/qemu-12407-qtest.sock -accel qtest > -nodefaults -display none -accel qtest -machine virt -drive > if=none,id=drive0,file=/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,node-name=top,backing.node-name=mid,backing.backing.node-name=base > -device virtio-scsi -device scsi-hd,id=scsi0,drive=drive0' > +ERROR:qemu.machine.machine:Output: "qemu-system-aarch64: -chardev > socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock: Failed to > connect to '/tmp/tmp1h12r7ev/qemu-12407-monitor.sock': No such file or > directory\n" ... Oh. That's unpleasant. My guess is that we aren't listening on the socket before the QEMU process gets far enough to want to connect to it. The change to an asynchronous backend must have jostled the timing. > +ERROR:qemu.machine.machine:exitcode: 1 And, oh: The VM launching library only chirps about *negative* error codes. That's why it wasn't printing anything more useful. I suppose the thinking was that we use the VM launch utility to knowingly launch bad command lines, so we only wanted to see failure notifications on -errno style codes, but that obviously makes debugging unintentional failures a lot more awful. I'll try to improve the usability and legibility of the errors here. Thanks, --js
Re: iotest 040, 041, intermittent failure in netbsd VM
On 1/18/22 12:08 AM, John Snow wrote:
On Mon, Jan 17, 2022 at 3:49 PM Peter Maydell wrote:
On Mon, 17 Jan 2022 at 20:35, John Snow 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.mayd...@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
.
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(
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, 17 Jan 2022 at 20:35, John Snow wrote: > I do expect this to print more information on failure than it > currently is, though (bug somewhere in machine.py, I think). > 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? Having fixed my setup to not use an ancient host QEMU, here's the relevant bit of the log: TEST iotest-qcow2: 037 TEST iotest-qcow2: 038 [not run] TEST iotest-qcow2: 039 [not run] TEST iotest-qcow2: 040 [fail] QEMU -- "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64" -nodefaults -display none -accel qtest -machine virt QEMU_IMG -- "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-img" QEMU_IO -- "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-io" --cache writeback --aio threads -f qcow2 QEMU_NBD -- "/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-nbd" IMGFMT-- qcow2 IMGPROTO -- file PLATFORM -- NetBSD/amd64 localhost 9.2 TEST_DIR -- /home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch SOCK_DIR -- /tmp/tmp1h12r7ev GDB_OPTIONS -- VALGRIND_QEMU -- PRINT_QEMU_OUTPUT -- --- /home/qemu/qemu-test.vdrI02/src/tests/qemu-iotests/040.out +++ 040.out.bad @@ -1,5 +1,95 @@ -. +...ERROR:qemu.aqmp.qmp_client.qemu-12407:Failed to establish connection: concurrent.futures._base.CancelledError +ERROR:qemu.machine.machine:Error launching VM +ERROR:qemu.machine.machine:Process was forked, waiting on it +ERROR:qemu.machine.machine:Command: '/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64 -display none -vga none -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock -mon chardev=mon,mode=control -qtest unix:path=/tmp/tmp1h12r7ev/qemu-12407-qtest.sock -accel qtest -nodefaults -display none -accel qtest -machine virt -drive if=none,id=drive0,file=/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,node-name=top,backing.node-name=mid,backing.backing.node-name=base -device virtio-scsi -device scsi-hd,id=scsi0,drive=drive0' +ERROR:qemu.machine.machine:Output: "qemu-system-aarch64: -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock: Failed to connect to '/tmp/tmp1h12r7ev/qemu-12407-monitor.sock': No such file or directory\n" +ERROR:qemu.machine.machine:exitcode: 1 +E..ERROR:qemu.aqmp.qmp_client.qemu-12407:Failed to establish connection: concurrent.futures._base.CancelledError +ERROR:qemu.machine.machine:Error launching VM +ERROR:qemu.machine.machine:Process was forked, waiting on it +ERROR:qemu.machine.machine:Command: '/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64 -display none -vga none -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock -mon chardev=mon,mode=control -qtest unix:path=/tmp/tmp1h12r7ev/qemu-12407-qtest.sock -accel qtest -nodefaults -display none -accel qtest -machine virt -drive if=none,id=drive0,file=/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,node-name=top,backing.node-name=mid,backing.backing.node-name=base -device virtio-scsi -device scsi-hd,id=scsi0,drive=drive0' +ERROR:qemu.machine.machine:Output: "qemu-system-aarch64: -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock: Failed to connect to '/tmp/tmp1h12r7ev/qemu-12407-monitor.sock': No such file or directory\n" +ERROR:qemu.machine.machine:exitcode: 1 +EERROR:qemu.aqmp.qmp_client.qemu-12407:Failed to establish connection: concurrent.futures._base.CancelledError +ERROR:qemu.machine.machine:Error launching VM +ERROR:qemu.machine.machine:Process was forked, waiting on it +ERROR:qemu.machine.machine:Command: '/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/../../qemu-system-aarch64 -display none -vga none -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock -mon chardev=mon,mode=control -qtest unix:path=/tmp/tmp1h12r7ev/qemu-12407-qtest.sock -accel qtest -nodefaults -display none -accel qtest -machine virt -drive if=none,id=drive0,file=/home/qemu/qemu-test.vdrI02/build/tests/qemu-iotests/scratch/test.img,format=qcow2,cache=writeback,aio=threads,node-name=top,backing.node-name=mid,backing.backing.node-name=base -device virtio-scsi -device scsi-hd,id=scsi0,drive=drive0' +ERROR:qemu.machine.machine:Output: "qemu-system-aarch64: -chardev socket,id=mon,path=/tmp/tmp1h12r7ev/qemu-12407-monitor.sock: Failed to connect to '/tmp/tmp1h12r7ev/qemu-12407-monitor.sock': No such file or directory\n" +ERROR:qemu.machine.machine:exitcode: 1 +E. +== +ERROR: test_device_not_found (__main__.TestActiveZeroLengthImage) +-
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, 17 Jan 2022 at 23:09, John Snow wrote: > 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. Whoops, I hadn't realised I was running with that ancient a QEMU. For the scripted runs I set the PATH to include a 5.0 QEMU, but this by-hand command-line invocation of 'make' didn't do that, so it got the ancient system QEMU. -- PMM
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, Jan 17, 2022 at 3:49 PM Peter Maydell wrote:
>
> On Mon, 17 Jan 2022 at 20:35, John Snow 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.mayd...@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
> .
> 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 sel
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, 17 Jan 2022 at 20:35, John Snow 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:
peter.mayd...@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
.
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": []
}
}
DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Negotiating capabilities ...
DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:--> {
"execute": "qmp_capabilities",
"arguments": {
"enable": []
}
}
DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:<-- {
"error": {
"class": "GenericError",
"desc": "Parameter 'enable' is unexpected"
}
}
ERROR:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Negotiation failed:
AssertionError
DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Negotiation failed:
| Traceback (most recent call last):
| File
"/home/peter.maydell/qemu-netbsd/tests/vm/../../python/qemu/aqmp/qmp_client.py",
line 306, in _negotiate
| assert 'return' in reply
| AssertionError
ERROR:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Failed to establish
session: qemu.aqmp.qmp_client.NegotiationError: Negotiation failed:
DEBUG:qemu.aqmp.qmp_client.qemu-2335-7f3b78d7f128:Failed to establish session:
| Traceback (most recent call last):
| File
"/home/peter.maydell/qemu-netbsd/tests/vm/../../python/qemu/aqmp/qmp_client.py",
line 306, in _negotiate
| assert 'return' in reply
| AssertionError
|
| The above exception was the direct cause o
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, 17 Jan 2022 at 20:35, John Snow wrote: > > On Mon, Jan 17, 2022 at 5:05 AM Kevin Wolf wrote: > > > > Am 10.01.2022 um 16:55 hat Peter Maydell geschrieben: > > > Just saw this failure of iotests in a netbsd VM > This trace says that we timed out while awaiting a connection from > QEMU during the VM launch phase. i.e. python/qemu/qmp/machine.py line > 340: > > def _post_launch(self) -> None: > if self._qmp_connection: > self._qmp.accept(self._qmp_timer) <-- we timed out here. > > (Note to self: make this traceback look more obvious as to what was > canceled and why. I think I can improve readability here a bit ...) > > Sky's the limit on why QEMU never connected to the socket, but: > > > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040.out > > > fcntl(): Invalid argument > > That looks fairly suspicious, and I don't know which process was > responsible for printing it (or when, relative to the other outputs). > I assume you don't see any such output like this on a good run. The NetBSD VM prints those fcntl messages all over the place. I think something in the build system (make? ninja? who knows) triggers them. > > > -OK > > > +FAILED (errors=1) > > > TEST iotest-qcow2: 041 [fail] > > > QEMU -- > > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" > > > -nodefaults -display none -accel qtest -machine virt > > > QEMU_IMG -- > > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" > > > QEMU_IO -- > > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" > > > --cache writeback --aio threads -f qcow2 > > > QEMU_NBD -- > > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" > > > IMGFMT-- qcow2 > > > IMGPROTO -- file > > > PLATFORM -- NetBSD/amd64 localhost 9.2 > > > TEST_DIR -- > > > /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch > > > SOCK_DIR -- /tmp/tmpuniuicbi > > > GDB_OPTIONS -- > > > VALGRIND_QEMU -- > > > PRINT_QEMU_OUTPUT -- > > > > > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041.out > > > +++ 041.out.bad > > > @@ -1,5 +1,32 @@ > > > -... > > > +..ERROR:qemu.aqmp.qmp_client.qemu-15252:Failed > > > to establish connection: concurrent.futures._base.CancelledError > > > +E > > > +== > > > +ERROR: test_small_buffer (__main__.TestSingleBlockdev) > > > +-- > > > +Traceback (most recent call last): > > > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line > > > 233, in setUp > > > +TestSingleDrive.setUp(self) > > > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line > > > 54, in setUp > > > +self.vm.launch() > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > > line 399, in launch > > > +self._launch() > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > > line 434, in _launch > > > +self._post_launch() > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/qtest.py", > > > line 147, in _post_launch > > > +super()._post_launch() > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > > line 340, in _post_launch > > > +self._qmp.accept(self._qmp_timer) > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > > > line 69, in accept > > > +timeout > > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > > > line 42, in _sync > > > +asyncio.wait_for(future, timeout=timeout) > > > + File "/usr/pkg/lib/python3.7/asyncio/base_events.py", line 587, in > > > run_until_complete > > > +return future.result() > > > + File "/usr/pkg/lib/python3.7/asyncio/tasks.py", line 449, in wait_for > > > +raise futures.TimeoutError() > > > +concurrent.futures._base.TimeoutError > > Same problem here, except I don't see any output from QEMU to blame. > As far as the Python code knows, it just never got a connection on the > socket, so it timed out and died. I think the NetBSD VM does for some reason get a bit slow to do stuff. I've never worked out why. In the past we've had to bump up various overoptimistic timeouts to help it out. > I do expect this to print more information on failure than it > currently is, though (bug somewhere in machine.py, I think). > 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? > > diff --git a/python/qemu/machine/machine.py b/python/qemu/machine/machine.py > index 67ab06ca2b..ca49e6fcd2 100644 > --- a/python/qemu/machine/
Re: iotest 040, 041, intermittent failure in netbsd VM
On Mon, Jan 17, 2022 at 5:05 AM Kevin Wolf wrote: > > Am 10.01.2022 um 16:55 hat Peter Maydell geschrieben: > > Just saw this failure of iotests in a netbsd VM (the in-tree > > tests/vm stuff). Pretty sure it's an intermittent as the > > pulreq being tested has nothing io or block related. > > > > > > TEST iotest-qcow2: 036 > > TEST iotest-qcow2: 037 > > TEST iotest-qcow2: 038 [not run] > > TEST iotest-qcow2: 039 [not run] > > TEST iotest-qcow2: 040 [fail] > > QEMU -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" > > -nodefaults -display none -accel qtest -machine > > virt > > QEMU_IMG -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" > > QEMU_IO -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" > > --cache writeback --aio threads -f qcow2 > > QEMU_NBD -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" > > IMGFMT-- qcow2 > > IMGPROTO -- file > > PLATFORM -- NetBSD/amd64 localhost 9.2 > > TEST_DIR -- > > /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch > > SOCK_DIR -- /tmp/tmpuniuicbi > > GDB_OPTIONS -- > > VALGRIND_QEMU -- > > PRINT_QEMU_OUTPUT -- > > > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040.out > > fcntl(): Invalid argument > > +++ 040.out.bad > > @@ -1,5 +1,30 @@ > > -. > > +ERROR:qemu.aqmp.qmp_client.qemu-7648:Failed > > to establish connection: concurrent.futures._base.CancelledError > > +E > > +== > > +ERROR: test_top_is_default_active (__main__.TestSingleDrive) > > +-- > > +Traceback (most recent call last): > > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040", line > > 94, in setUp > > +self.vm.launch() > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > line 399, in launch > > +self._launch() > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > line 434, in _launch > > +self._post_launch() > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/qtest.py", > > line 147, in _post_launch > > +super()._post_launch() > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > > line 340, in _post_launch > > +self._qmp.accept(self._qmp_timer) > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > > line 69, in accept > > +timeout > > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > > line 42, in _sync > > +asyncio.wait_for(future, timeout=timeout) > > + File "/usr/pkg/lib/python3.7/asyncio/base_events.py", line 587, in > > run_until_complete > > +return future.result() > > + File "/usr/pkg/lib/python3.7/asyncio/tasks.py", line 449, in wait_for > > +raise futures.TimeoutError() > > +concurrent.futures._base.TimeoutError > > + > > -- > > Ran 65 tests > > This trace says that we timed out while awaiting a connection from QEMU during the VM launch phase. i.e. python/qemu/qmp/machine.py line 340: def _post_launch(self) -> None: if self._qmp_connection: self._qmp.accept(self._qmp_timer) <-- we timed out here. (Note to self: make this traceback look more obvious as to what was canceled and why. I think I can improve readability here a bit ...) Sky's the limit on why QEMU never connected to the socket, but: > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040.out > > fcntl(): Invalid argument That looks fairly suspicious, and I don't know which process was responsible for printing it (or when, relative to the other outputs). I assume you don't see any such output like this on a good run. > > -OK > > +FAILED (errors=1) > > TEST iotest-qcow2: 041 [fail] > > QEMU -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" > > -nodefaults -display none -accel qtest -machine virt > > QEMU_IMG -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" > > QEMU_IO -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" > > --cache writeback --aio threads -f qcow2 > > QEMU_NBD -- > > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" > > IMGFMT-- qcow2 > > IMGPROTO -- file > > PLATFORM -- NetBSD/amd64 localhost 9.2 > > TEST_DIR -- > > /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch > > SOCK_DIR -- /tmp/tmpuniuicbi > > GDB_OPTIONS -- > > VALGRIND_QEMU -- > > PRINT_QEMU_OUTPUT -- > > > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041.out > > +++ 041.out.bad > > @@ -1,5 +1,32 @@ >
Re: iotest 040, 041, intermittent failure in netbsd VM
Am 10.01.2022 um 16:55 hat Peter Maydell geschrieben: > Just saw this failure of iotests in a netbsd VM (the in-tree > tests/vm stuff). Pretty sure it's an intermittent as the > pulreq being tested has nothing io or block related. > > > TEST iotest-qcow2: 036 > TEST iotest-qcow2: 037 > TEST iotest-qcow2: 038 [not run] > TEST iotest-qcow2: 039 [not run] > TEST iotest-qcow2: 040 [fail] > QEMU -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" > -nodefaults -display none -accel qtest -machine > virt > QEMU_IMG -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" > QEMU_IO -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" > --cache writeback --aio threads -f qcow2 > QEMU_NBD -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" > IMGFMT-- qcow2 > IMGPROTO -- file > PLATFORM -- NetBSD/amd64 localhost 9.2 > TEST_DIR -- /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch > SOCK_DIR -- /tmp/tmpuniuicbi > GDB_OPTIONS -- > VALGRIND_QEMU -- > PRINT_QEMU_OUTPUT -- > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040.out > fcntl(): Invalid argument > +++ 040.out.bad > @@ -1,5 +1,30 @@ > -. > +ERROR:qemu.aqmp.qmp_client.qemu-7648:Failed > to establish connection: concurrent.futures._base.CancelledError > +E > +== > +ERROR: test_top_is_default_active (__main__.TestSingleDrive) > +-- > +Traceback (most recent call last): > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040", line > 94, in setUp > +self.vm.launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > line 399, in launch > +self._launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > line 434, in _launch > +self._post_launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/qtest.py", > line 147, in _post_launch > +super()._post_launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > line 340, in _post_launch > +self._qmp.accept(self._qmp_timer) > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > line 69, in accept > +timeout > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", > line 42, in _sync > +asyncio.wait_for(future, timeout=timeout) > + File "/usr/pkg/lib/python3.7/asyncio/base_events.py", line 587, in > run_until_complete > +return future.result() > + File "/usr/pkg/lib/python3.7/asyncio/tasks.py", line 449, in wait_for > +raise futures.TimeoutError() > +concurrent.futures._base.TimeoutError > + > -- > Ran 65 tests > > -OK > +FAILED (errors=1) > TEST iotest-qcow2: 041 [fail] > QEMU -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" > -nodefaults -display none -accel qtest -machine virt > QEMU_IMG -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" > QEMU_IO -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" > --cache writeback --aio threads -f qcow2 > QEMU_NBD -- > "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" > IMGFMT-- qcow2 > IMGPROTO -- file > PLATFORM -- NetBSD/amd64 localhost 9.2 > TEST_DIR -- /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch > SOCK_DIR -- /tmp/tmpuniuicbi > GDB_OPTIONS -- > VALGRIND_QEMU -- > PRINT_QEMU_OUTPUT -- > > --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041.out > +++ 041.out.bad > @@ -1,5 +1,32 @@ > -... > +..ERROR:qemu.aqmp.qmp_client.qemu-15252:Failed > to establish connection: concurrent.futures._base.CancelledError > +E > +== > +ERROR: test_small_buffer (__main__.TestSingleBlockdev) > +-- > +Traceback (most recent call last): > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line > 233, in setUp > +TestSingleDrive.setUp(self) > + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line > 54, in setUp > +self.vm.launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > line 399, in launch > +self._launch() > + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", > line 434, in _launch > +
iotest 040, 041, intermittent failure in netbsd VM
Just saw this failure of iotests in a netbsd VM (the in-tree tests/vm stuff). Pretty sure it's an intermittent as the pulreq being tested has nothing io or block related. TEST iotest-qcow2: 036 TEST iotest-qcow2: 037 TEST iotest-qcow2: 038 [not run] TEST iotest-qcow2: 039 [not run] TEST iotest-qcow2: 040 [fail] QEMU -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" -nodefaults -display none -accel qtest -machine virt QEMU_IMG -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" QEMU_IO -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" --cache writeback --aio threads -f qcow2 QEMU_NBD -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" IMGFMT-- qcow2 IMGPROTO -- file PLATFORM -- NetBSD/amd64 localhost 9.2 TEST_DIR -- /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch SOCK_DIR -- /tmp/tmpuniuicbi GDB_OPTIONS -- VALGRIND_QEMU -- PRINT_QEMU_OUTPUT -- --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040.out fcntl(): Invalid argument +++ 040.out.bad @@ -1,5 +1,30 @@ -. +ERROR:qemu.aqmp.qmp_client.qemu-7648:Failed to establish connection: concurrent.futures._base.CancelledError +E +== +ERROR: test_top_is_default_active (__main__.TestSingleDrive) +-- +Traceback (most recent call last): + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/040", line 94, in setUp +self.vm.launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 399, in launch +self._launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 434, in _launch +self._post_launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/qtest.py", line 147, in _post_launch +super()._post_launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 340, in _post_launch +self._qmp.accept(self._qmp_timer) + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", line 69, in accept +timeout + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/aqmp/legacy.py", line 42, in _sync +asyncio.wait_for(future, timeout=timeout) + File "/usr/pkg/lib/python3.7/asyncio/base_events.py", line 587, in run_until_complete +return future.result() + File "/usr/pkg/lib/python3.7/asyncio/tasks.py", line 449, in wait_for +raise futures.TimeoutError() +concurrent.futures._base.TimeoutError + -- Ran 65 tests -OK +FAILED (errors=1) TEST iotest-qcow2: 041 [fail] QEMU -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-system-aarch64" -nodefaults -display none -accel qtest -machine virt QEMU_IMG -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-img" QEMU_IO -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-io" --cache writeback --aio threads -f qcow2 QEMU_NBD -- "/home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/../../qemu-nbd" IMGFMT-- qcow2 IMGPROTO -- file PLATFORM -- NetBSD/amd64 localhost 9.2 TEST_DIR -- /home/qemu/qemu-test.MPWquy/build/tests/qemu-iotests/scratch SOCK_DIR -- /tmp/tmpuniuicbi GDB_OPTIONS -- VALGRIND_QEMU -- PRINT_QEMU_OUTPUT -- --- /home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041.out +++ 041.out.bad @@ -1,5 +1,32 @@ -... +..ERROR:qemu.aqmp.qmp_client.qemu-15252:Failed to establish connection: concurrent.futures._base.CancelledError +E +== +ERROR: test_small_buffer (__main__.TestSingleBlockdev) +-- +Traceback (most recent call last): + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line 233, in setUp +TestSingleDrive.setUp(self) + File "/home/qemu/qemu-test.MPWquy/src/tests/qemu-iotests/041", line 54, in setUp +self.vm.launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 399, in launch +self._launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 434, in _launch +self._post_launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/qtest.py", line 147, in _post_launch +super()._post_launch() + File "/home/qemu/qemu-test.MPWquy/src/python/qemu/machine/machine.py", line 340, in _post_launch +self._qmp.accept(self._qmp_timer) +
