Project

General

Profile

Actions
Copy link

action #53393

closed

"Migrate to file failed" when saving qemu qcow snapshot (test fails in prepare_test_data)

Added by okurz almost 5 years ago. Updated almost 5 years ago.

Status:
Rejected
Priority:
Normal
Assignee:
rpalethorpe
Category:
Regressions/Crashes
Target version:
-
Start date:
2019-06-21
Due date:
% Done:

0%

Estimated time:

Description

Observation

openQA test in scenario opensuse-Tumbleweed-KDE-Live-x86_64-kde-live@uefi-2G fails in
prepare_test_data

with

[2019-06-21T04:30:30.758 CEST] [debug] Backend process died, backend errors are reported below in the following lines:
Migrate to file failed at /usr/lib/os-autoinst/backend/qemu.pm line 250.

[2019-06-21T04:30:30.759 CEST] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2019-06-21T04:30:32.788 CEST] [debug] flushing frames
last frame
[2019-06-21T04:30:32.834 CEST] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2019-06-21T04:30:32.835 CEST] [debug] QEMU: Formatting '/var/lib/openqa/pool/15/raid/hd0-overlay2', fmt=qcow2 size=21474836480 backing_file=/var/lib/openqa/pool/15/raid/hd0-overlay1 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2019-06-21T04:30:32.835 CEST] [debug] QEMU: Formatting '/var/lib/openqa/pool/15/raid/cd0-overlay2', fmt=qcow2 size=968884224 backing_file=/var/lib/openqa/pool/15/raid/cd0-overlay1 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2019-06-21T04:30:32.835 CEST] [debug] QEMU: Formatting '/var/lib/openqa/pool/15/raid/pflash-code-overlay2', fmt=qcow2 size=1966080 backing_file=/var/lib/openqa/pool/15/raid/pflash-code-overlay1 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2019-06-21T04:30:32.835 CEST] [debug] QEMU: Formatting '/var/lib/openqa/pool/15/raid/pflash-vars-overlay2', fmt=qcow2 size=131072 backing_file=/var/lib/openqa/pool/15/raid/pflash-vars-overlay1 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2019-06-21T04:30:32.835 CEST] [debug] QEMU: qemu-system-x86_64: terminating on signal 15 from pid 18246 (/usr/bin/isotovideo: backen)
[2019-06-21T04:30:32.836 CEST] [debug] sending magic and exit
[2019-06-21T04:30:32.836 CEST] [debug] received magic close
[2019-06-21T04:30:32.837 CEST] [debug] THERE IS NOTHING TO READ 15 4 3
[2019-06-21T04:30:32.837 CEST] [debug] killing command server 18223 because test execution ended
[2019-06-21T04:30:32.837 CEST] [debug] isotovideo: informing websocket clients before stopping command server: http://127.0.0.1:20153/YtnqrnSljG_6dzxm/broadcast
[2019-06-21T04:30:32.848 CEST] [debug] backend process exited: 0
[2019-06-21T04:30:47.852 CEST] [debug] isotovideo: unable to inform websocket clients about stopping command server: Request timeout at /usr/bin/isotovideo line 172.

[2019-06-21T04:30:48.855 CEST] [error] can_read received kill signal at /usr/lib/os-autoinst/myjsonrpc.pm line 91.

[2019-06-21T04:30:48.863 CEST] [debug] commands process exited: 0
[2019-06-21T04:30:49.864 CEST] [debug] done with command server
[2019-06-21T04:30:49.864 CEST] [debug] killing autotest process 18225
[2019-06-21T04:30:49.864 CEST] [debug] sysread failed: 
[2019-06-21T04:30:49.864 CEST] [debug] ||| starting consoletest_setup tests/console/consoletest_setup.pm
syswrite failed Broken pipe at /usr/lib/os-autoinst/myjsonrpc.pm line 40.
    myjsonrpc::send_json(GLOB(0x562f5d142b10), HASH(0x562f5d183cb0)) called at /usr/lib/os-autoinst/autotest.pm line 321
    autotest::query_isotovideo("set_current_test", HASH(0x562f5f65b3c8)) called at /usr/lib/os-autoinst/autotest.pm line 182
    autotest::set_current_test(consoletest_setup=HASH(0x562f5ec3f578)) called at /usr/lib/os-autoinst/basetest.pm line 275
    basetest::start(consoletest_setup=HASH(0x562f5ec3f578)) called at /usr/lib/os-autoinst/autotest.pm line 358
    autotest::runalltests() called at /usr/lib/os-autoinst/autotest.pm line 222
    eval {...} called at /usr/lib/os-autoinst/autotest.pm line 222
    autotest::run_all() called at /usr/lib/os-autoinst/autotest.pm line 275
    autotest::__ANON__(Mojo::IOLoop::ReadWriteProcess=HASH(0x562f5f0c2430)) called at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop/ReadWriteProcess.pm line 325
    eval {...} called at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop/ReadWriteProcess.pm line 325
    Mojo::IOLoop::ReadWriteProcess::_fork(Mojo::IOLoop::ReadWriteProcess=HASH(0x562f5f0c2430), CODE(0x562f5f13c008)) called at /usr/lib/perl5/vendor_perl/5.26.1/Mojo/IOLoop/ReadWriteProcess.pm line 476
    Mojo::IOLoop::ReadWriteProcess::start(Mojo::IOLoop::ReadWriteProcess=HASH(0x562f5f0c2430)) called at /usr/lib/os-autoinst/autotest.pm line 276
    autotest::start_process() called at /usr/bin/isotovideo line 304
[2019-06-21T04:30:49.869 CEST] [debug] [autotest] process exited: 0

with the most important line "Migrate to file failed at /usr/lib/os-autoinst/backend/qemu.pm line 250."

Further details

Always latest result in this scenario: latest

Actions
Copy link
 #1

Updated by okurz almost 5 years ago

  • Project changed from openQA Tests to openQA Project
  • Category changed from Bugs in existing tests to Regressions/Crashes
Actions
Copy link
 #2

Updated by rpalethorpe almost 5 years ago

  • Status changed from New to Rejected

From just above your snippet, there is a message from QEMU:
"EVENT {"data":{"status":"failed"},"event":"MIGRATION","timestamp":{"microseconds":715336,"seconds":1561084230}}"

So QEMU stopped the migration for some reason and it didn't appear to write another log message. If it did, it should have been printed into the os-autoinst log when it closed QEMU.

Possibly the worker ran out of disk space, RAM or there was some random FS error. It seems that it is passing now, so I will just close this. It would be helpful if QEMU reported more information, but that is a separate issue.

Actions
Copy link
 #3

Updated by okurz almost 5 years ago

agreed, thanks for looking into this anyway.

Actions
Copy link

Also available in: Atom PDF