action #55514
closedjob failed to lastgood snapshot "Could not open backing file: Could not open backing file: Could not open …"
0%
Description
Observation¶
https://openqa.opensuse.org/tests/1006480/file/autoinst-log.txt shows an incomplete:
[2019-08-14T12:47:47.240 CEST] [debug] running /usr/bin/qemu-img create -f qcow2 -b /var/lib/openqa/pool/9/raid/cd0-overlay13 /var/lib/openqa/pool/9/raid/cd0-overlay14 4045406208
[2019-08-14T12:47:47.275 CEST] [debug] qemu-img: warning: Could not verify backing image. This may become an error in future versions.
Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open '/var/lib/openqa/pool/9/openSUSE-Leap-15.2-DVD-x86_64-Build483.2-Media.iso': No such file or directory
Formatting '/var/lib/openqa/pool/9/raid/cd0-overlay14', fmt=qcow2 size=4045406208 backing_file=/var/lib/openqa/pool/9/raid/cd0-overlay13 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2019-08-14T12:47:47.275 CEST] [debug] starting: /usr/bin/qemu-system-x86_64 -only-migratable -chardev ringbuf,id=serial0,logfile=serial0,logappend=on -serial chardev:serial0 -soundhw ac97 -global isa-fdc.driveA= -m 2048 -machine pc-i440fx-2.4 -cpu qemu64 -netdev user,id=qanet0 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -smbios file=/usr/lib/os-autoinst/dmidata/dell_e6330/smbios_type_1.bin -smbios file=/usr/lib/os-autoinst/dmidata/dell_e6330/smbios_type_2.bin -smbios file=/usr/lib/os-autoinst/dmidata/dell_e6330/smbios_type_3.bin -boot once=d,menu=on,splash-time=5000 -device usb-ehci -device usb-tablet -smp 1 -enable-kvm -no-shutdown -vnc :99,share=force-shared -device virtio-serial -chardev pipe,id=virtio_console,path=virtio_console,logfile=virtio_console.log,logappend=on -device virtconsole,chardev=virtio_console,name=org.openqa.console.virtio_console -chardev socket,path=qmp_socket,server,nowait,id=qmp_socket,logfile=qmp_socket.log,logappend=on -qmp chardev:qmp_socket -S -device virtio-scsi-pci,id=scsi0 -blockdev driver=file,node-name=hd0-overlay14-file,filename=/var/lib/openqa/pool/9/raid/hd0-overlay14,cache.no-flush=on -blockdev driver=qcow2,node-name=hd0-overlay14,file=hd0-overlay14-file,cache.no-flush=on -device virtio-blk,id=hd0-device,drive=hd0-overlay14,serial=hd0 -blockdev driver=file,node-name=cd0-overlay14-file,filename=/var/lib/openqa/pool/9/raid/cd0-overlay14,cache.no-flush=on -blockdev driver=qcow2,node-name=cd0-overlay14,file=cd0-overlay14-file,cache.no-flush=on -device scsi-cd,id=cd0-device,drive=cd0-overlay14,serial=cd0 -incoming defer
[2019-08-14T12:47:47.287 CEST] [debug] Waiting for 0 attempts
[2019-08-14T12:47:47.408 CEST] [debug] Waiting for 1 attempts
[2019-08-14T12:47:48.409 CEST] [debug] Waiting for 2 attempts
[2019-08-14T12:47:49.409 CEST] [debug] Waiting for 3 attempts
[2019-08-14T12:47:50.410 CEST] [debug] Waiting for 4 attempts
[2019-08-14T12:47:51.410 CEST] [debug] Waiting for 5 attempts
[2019-08-14T12:47:52.410 CEST] [debug] Waiting for 6 attempts
[2019-08-14T12:47:53.411 CEST] [debug] Waiting for 7 attempts
[2019-08-14T12:47:54.411 CEST] [debug] Waiting for 8 attempts
[2019-08-14T12:47:55.412 CEST] [debug] Waiting for 9 attempts
[2019-08-14T12:47:56.412 CEST] [debug] Waiting for 10 attempts
[2019-08-14T12:47:57.412 CEST] [debug] Waiting for 11 attempts
[2019-08-14T12:47:58.413 CEST] [debug] Waiting for 12 attempts
[2019-08-14T12:47:59.413 CEST] [debug] Waiting for 13 attempts
[2019-08-14T12:48:00.414 CEST] [debug] Waiting for 14 attempts
[2019-08-14T12:48:01.414 CEST] [debug] Waiting for 15 attempts
[2019-08-14T12:48:02.414 CEST] [debug] Waiting for 16 attempts
[2019-08-14T12:48:03.415 CEST] [debug] Waiting for 17 attempts
[2019-08-14T12:48:04.415 CEST] [debug] Waiting for 18 attempts
[2019-08-14T12:48:05.416 CEST] [debug] Waiting for 19 attempts
[2019-08-14T12:48:06.416 CEST] [debug] Backend process died, backend errors are reported below in the following lines:
can't open qmp at /usr/lib/os-autoinst/OpenQA/Qemu/Proc.pm line 405.
[2019-08-14T12:48:06.416 CEST] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2019-08-14T12:48:06.419 CEST] [debug] flushing frames
last frame
[2019-08-14T12:48:06.447 CEST] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2019-08-14T12:48:06.449 CEST] [debug] QEMU: QEMU emulator version 3.1.0 (openSUSE Leap 15.1)
[2019-08-14T12:48:06.449 CEST] [debug] QEMU: Copyright (c) 2003-2018 Fabrice Bellard and the QEMU Project developers
[2019-08-14T12:48:06.449 CEST] [debug] QEMU: qemu-system-x86_64: -blockdev driver=qcow2,node-name=cd0-overlay14,file=cd0-overlay14-file,cache.no-flush=on: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open '/var/lib/openqa/pool/9/openSUSE-Leap-15.2-DVD-x86_64-Build483.2-Media.iso': No such file or directory
Problem¶
The recursive error message is interesting: "Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open '/var/lib/openqa/pool/9/openSUSE-Leap-15.2-DVD-x86_64-Build483.2-Media.iso': No such file or directory"
Updated by okurz over 4 years ago
- Copied from action #55511: job failed to revert to lastgood snapshot "Could not open backing file: Could not open '/var/lib/openqa/pool/2/….iso': No such file or directory" added
Updated by okurz over 4 years ago
https://openqa.opensuse.org/tests/1006675/file/autoinst-log.txt is another example with:
[2019-08-14T14:27:21.981 CEST] [debug] QEMU: qemu-system-x86_64: -blockdev driver=qcow2,node-name=hd0-overlay12,file=hd0-overlay12-file,cache.no-flush=on: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open backing file: Could not open '/var/lib/openqa/pool/5/opensuse-15.0-x86_64-GM-cryptlvm@uefi.qcow2': No such file or directory
Updated by okurz over 4 years ago
https://openqa.opensuse.org/tests/1006791# another one
Updated by okurz over 4 years ago
I wonder if maybe
commit 507f634f (okurz/enhance/no_blank_line_no_warnings, enhance/no_blank_line_no_warnings)
Author: Oliver Kurz <okurz@suse.de>
Date: Tue Aug 6 11:45:54 2019 +0200
Fix blank line on process output
Previously e.g. the call to qemu-img would output a line with
'Formatting' with a following newline causing an unnecessary blank line
in the output.
diff --git a/osutils.pm b/osutils.pm
index c6525fd9..b94b299a 100644
--- a/osutils.pm
+++ b/osutils.pm
@@ -107,6 +107,7 @@ sub _run {
$p->wait_stop;
close($p->$_ ? $p->$_ : ()) for qw(read_stream write_stream error_stream);
+ chomp($out) if $out;
return $p->exit_status, $out;
}
broke this?
Updated by rpalethorpe over 4 years ago
It manages to take 10-13 snapshots before this happens. I would expect that removing any chars would cause it to fail first time.
Could not open '/var/lib/openqa/pool/11/opensuse-42.3-x86_64-GM-cryptlvm@uefi.qcow2': No such file or directory
I can't see anything wrong with the path and this is the original backing file which has already been used 10-13 times. So I suspect file corruption.
Updated by okurz over 4 years ago
rpalethorpe wrote:
[…] So I suspect file corruption.
Thanks for your answer. I could also not reproduce this yet. I wonder about the recursive message though if it's part of the problem or only a weird symptom as consequence. Maybe we can reproduce this when saving really many snapshots from many modules and then only failing in very late ones.
Updated by coolo over 4 years ago
This is a super-dup of https://progress.opensuse.org/issues/46742 - and IMO https://progress.opensuse.org/issues/40871 is not fixed, just made less likely, somehow
Updated by okurz over 4 years ago
- Related to action #40871: Asset removed during job runtime added
Updated by coolo over 4 years ago
super-dup (m):
A duplicate bug entry you filed yourself 7 months ago and forgot about it meanwhile
Why do I have to explain everything here?
Updated by rpalethorpe over 4 years ago
- Status changed from New to Rejected
I think the existing bugs are good enough.
Updated by okurz over 4 years ago
I fail to understand why the error message recurses though …
Updated by rpalethorpe over 4 years ago
Probably because QEMU is recursively calling the same function for each backing file.