Project

General

Profile

action #55514

job failed to lastgood snapshot "Could not open backing file: Could not open backing file: Could not open …"

Added by okurz over 3 years ago. Updated over 3 years ago.

Status:
Rejected
Priority:
High
Assignee:
Category:
Concrete Bugs
Target version:
-
Start date:
2019-08-14
Due date:
% Done:

0%

Estimated time:
Difficulty:

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"


Related issues

Related to openQA Project - action #40871: Asset removed during job runtimeResolved2018-09-11

Copied from openQA Project - 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"Rejected2019-08-14

History

#1 Updated by okurz over 3 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

#2 Updated by okurz over 3 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

#4 Updated by okurz over 3 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?

#5 Updated by rpalethorpe over 3 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.

#6 Updated by okurz over 3 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.

#7 Updated by coolo over 3 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

#8 Updated by okurz over 3 years ago

  • Related to action #40871: Asset removed during job runtime added

#9 Updated by okurz over 3 years ago

what's a "super-dup"?

#10 Updated by coolo over 3 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?

#11 Updated by rpalethorpe over 3 years ago

  • Status changed from New to Rejected

I think the existing bugs are good enough.

#12 Updated by okurz over 3 years ago

I fail to understand why the error message recurses though …

#13 Updated by rpalethorpe over 3 years ago

Probably because QEMU is recursively calling the same function for each backing file.

Also available in: Atom PDF