QA » openQA Project » openQA Infrastructure

grep 'install|qemu|' /var/log/zypp/history reveals:

2020-04-07 12:16:43|install|qemu|3.1.1.1-lp151.7.12.1|ppc64le||repo-update|8b47800ffb49b7264d2d3dd1e28110b21b5f29ac5eac3a275549de9b9d4839bd|
2020-06-02 12:17:31|install|qemu|3.1.1.1-lp151.7.15.2|ppc64le||repo-update|d73eb3b6a98363feb59bbfa5f2a9eaaff37fe1b59593f5cd119acbe6b21fb956|
2020-10-23 16:21:54|install|qemu|4.2.1-lp152.9.6.1|ppc64le||repo-update|a0139be34d5cf04e8dfbb960e9b9ea53cb0509afb4973cc289058d4249943755|

so qemu was upgraded from 3.1.1.1 to 4.2.1 during the openSUSE Leap 15.1->15.2 upgrade.

The root fs on power8 is ext4 so no snapper for easy rollback.

I tried manually on power8 with:

cd /var/lib/openqa/pool/6
curl http://openqa.opensuse.org/tests/1448500/file/vars.json > vars.json
isotovideo -d iso=/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-ppc64le-Snapshot20201024-Media.iso

which reproduced the error. Appending the suggested parameter shows a slightly different error messages. As it turns out we need to add multiple parameters, ending up with:

isotovideo -d iso=/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-ppc64le-Snapshot20201024-Media.iso qemumachine="cap-cfpc=broken,cap-sbbc=broken,cap-ibs=broken"

which shows a run succeeding to start qemu with:

[2020-10-25T15:36:21.491 UTC] [debug] Current version is 4.6.1603469837.f54bdeab [interface v20]
[2020-10-25T15:36:21.494 UTC] [debug] Setting forced test parameter ISO -> /var/lib/openqa/cache/openqa1-opensuse/openSUSE-Tumbleweed-DVD-ppc64le-Snapshot20201024-Media.iso
[2020-10-25T15:36:21.494 UTC] [debug] Setting forced test parameter QEMUMACHINE -> cap-cfpc=broken,cap-sbbc=broken,cap-ibs=broken
[2020-10-25T15:36:21.498 UTC] [debug] git hash in /var/lib/openqa/cache/openqa1-opensuse/tests/opensuse: c12d1da2e511d1cb87aeb302b752bc035a2c8c60
…
[2020-10-25T15:36:23.155 UTC] [debug] starting: /usr/bin/qemu-system-ppc64 -g 1024x768 -vga std -only-migratable -chardev ringbuf,id=serial0,logfile=serial0,logappend=on -serial chardev:serial0 -audiodev none,id=snd0 -device intel-hda -device hda-output,audiodev=snd0 -global isa-fdc.driveA= -m 4096 -machine cap-cfpc=broken,cap-sbbc=broken,cap-ibs=broken -cpu host -netdev user,id=qanet0 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -boot once=d -device nec-usb-xhci -device usb-tablet -device usb-kbd -smp 4 -enable-kvm -no-shutdown -vnc :96,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-file,filename=/var/lib/openqa/pool/6/raid/hd0,cache.no-flush=on -blockdev driver=qcow2,node-name=hd0,file=hd0-file,cache.no-flush=on -device virtio-blk,id=hd0-device,drive=hd0,serial=hd0 -blockdev driver=file,node-name=cd0-overlay0-file,filename=/var/lib/openqa/pool/6/raid/cd0-overlay0,cache.no-flush=on -blockdev driver=qcow2,node-name=cd0-overlay0,file=cd0-overlay0-file,cache.no-flush=on -device scsi-cd,id=cd0-device,drive=cd0-overlay0,serial=cd0
[2020-10-25T15:36:23.158 UTC] [debug] Waiting for 0 attempts
[2020-10-25T15:36:24.159 UTC] [debug] Waiting for 1 attempts
[2020-10-25T15:36:25.159 UTC] [debug] Finished after 2 attempts
[2020-10-25T15:36:25.159 UTC] [debug] QMP socket: 14
/usr/lib/os-autoinst/consoles/vnc_base.pm:62:{
  "port" => 5996,
  "connect_timeout" => 3,
  "hostname" => "localhost"
}
[2020-10-25T15:36:25.177 UTC] [debug] pointer type 0 0 640 480 -257
[2020-10-25T15:36:25.177 UTC] [debug] led state 0 1 1 -261
Start CPU
GOT GO

[2020-10-25T15:36:25.237 UTC] [debug] QEMU: QEMU emulator version 4.2.1 (openSUSE Leap 15.2)
[2020-10-25T15:36:25.237 UTC] [debug] QEMU: Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers
[2020-10-25T15:36:25.238 UTC] [debug] Snapshots are supported
[2020-10-25T15:36:25.239 UTC] [debug] ||| starting mediacheck tests/installation/mediacheck.pm
[2020-10-25T15:36:25.240 UTC] [debug] tests/installation/mediacheck.pm:23 called bootloader_setup::ensure_shim_import -> lib/bootloader_setup.pm:1063 called testapi::assert_screen
[2020-10-25T15:36:25.240 UTC] [debug] <<< testapi::assert_screen(mustmatch=[
  "inst-bootmenu",
  "bootloader-shim-import-prompt"
], timeout=30)
[2020-10-25T15:36:26.706 UTC] [debug] no match: 89.0s, best candidate: bootloader-tw-salt_installer-20190111 (0.29)
[2020-10-25T15:36:27.233 UTC] [debug] no change: 88.0s
[2020-10-25T15:36:28.466 UTC] [debug] no match: 87.0s, best candidate: bootloader-grub2-Kubic-boo1131693-20190405 (0.00)
[2020-10-25T15:36:29.458 UTC] [debug] no match: 86.0s, best candidate: bootloader-grub2-Kubic-boo1131693-20190405 (0.00)
[2020-10-25T15:36:31.052 UTC] [debug] WARNING: check_asserted_screen took 0.81 seconds for 17 candidate needles - make your needles more specific
[2020-10-25T15:36:31.052 UTC] [debug] no match: 85.0s, best candidate: bootloader-grub2-Kubic-boo1131693-20190405 (0.00)
[2020-10-25T15:36:31.575 UTC] [debug] >>> testapi::_handle_found_needle: found rescuesystem-20150721, similarity 1.00 @ 17/72
[2020-10-25T15:36:31.576 UTC] [debug] tests/installation/mediacheck.pm:24 called bootloader_setup::select_bootmenu_more -> lib/bootloader_setup.pm:598 called bootloader_setup::stop_grub_timeout -> lib/bootloader_setup.pm:79 called testapi::send_key
[2020-10-25T15:36:31.576 UTC] [debug] <<< testapi::send_key(key="up", do_wait=0, wait_screen_change=0)
[2020-10-25T15:36:31.978 UTC] [debug] tests/installation/mediacheck.pm:24 called bootloader_setup::select_bootmenu_more -> lib/bootloader_setup.pm:601 called testapi::check_screen
[2020-10-25T15:36:31.978 UTC] [debug] <<< testapi::check_screen(mustmatch="inst-submenu-more", timeout=0)
[2020-10-25T15:36:32.390 UTC] [debug] no match: -0.3s, best candidate: inst-submenu-more-20191210 (0.00)
[2020-10-25T15:36:32.554 UTC] [debug] >>> testapi::_check_backend_response: match=inst-submenu-more timed out after 0 (check_screen)
[2020-10-25T15:36:32.584 UTC] [debug] tests/installation/mediacheck.pm:24 called bootloader_setup::select_bootmenu_more -> lib/bootloader_setup.pm:605 called testapi::send_key_until_needlematch
[2020-10-25T15:36:32.584 UTC] [debug] <<< testapi::check_screen(mustmatch="inst-onmediacheck", timeout=3)
[2020-10-25T15:36:33.529 UTC] [debug] >>> testapi::_handle_found_needle: found mediacheck-20150610, similarity 1.00 @ 24/126
[2020-10-25T15:36:33.529 UTC] [debug] tests/installation/mediacheck.pm:24 called bootloader_setup::select_bootmenu_more -> lib/bootloader_setup.pm:624 called bootloader_setup::type_boot_parameters -> lib/bootloader_setup.pm:1330 called testapi::type_string
[2020-10-25T15:36:33.529 UTC] [debug] <<< testapi::type_string(string="    ", max_interval=4, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-10-25T15:36:36.040 UTC] [debug] tests/installation/mediacheck.pm:24 called bootloader_setup::select_bootmenu_more -> lib/bootloader_setup.pm:626 called testapi::send_key
[2020-10-25T15:36:36.040 UTC] [debug] <<< testapi::send_key(key="ret", wait_screen_change=0, do_wait=0)
[2020-10-25T15:36:36.441 UTC] [debug] tests/installation/mediacheck.pm:29 called testapi::assert_screen
[2020-10-25T15:36:36.441 UTC] [debug] <<< testapi::assert_screen(mustmatch=[
  "mediacheck-select-device",
  "mediacheck-ok",
  "mediacheck-checksum-wrong"
], timeout=3600)
[2020-10-25T15:36:36.492 UTC] [debug] no match: 10799.9s, best candidate: mediacheck-ok-20140903 (0.00)
^C[2020-10-25T15:36:36.557 UTC] [debug] isotovideo received signal INT
[2020-10-25T15:36:36.557 UTC] [debug] isotovideo received signal INT
[2020-10-25T15:36:36.557 UTC] [debug] stopping command server 25514 because test execution ended
[2020-10-25T15:36:36.557 UTC] [debug] QEMU: qemu-system-ppc64: terminating on signal 2
[2020-10-25T15:36:36.557 UTC] [debug] isotovideo: informing websocket clients before stopping command server: http://127.0.0.1:20063/qL0cvoaoKR5zOTFr/broadcast
[2020-10-25T15:36:36.558 UTC] [debug] commands process exited: 0
[2020-10-25T15:36:36.559 UTC] [debug] [autotest] process exited: 0
[2020-10-25T15:36:36.560 UTC] [debug] done with command server
[2020-10-25T15:36:36.560 UTC] [debug] stopping autotest process 25517
[2020-10-25T15:36:36.560 UTC] [debug] done with autotest process
[2020-10-25T15:36:36.560 UTC] [debug] isotovideo failed
[2020-10-25T15:36:36.560 UTC] [debug] stopping backend process 25537
[2020-10-25T15:36:36.561 UTC] [debug] backend got TERM
[2020-10-25T15:36:36.561 UTC] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2020-10-25T15:36:36.562 UTC] [debug] Passing remaining frames to the video encoder
[2020-10-25T15:36:36.563 UTC] [debug] Waiting for video encoder to finalize the video
[2020-10-25T15:36:36.563 UTC] [debug] The built-in video encoder (pid 25557) terminated
[2020-10-25T15:36:36.565 UTC] [debug] sending magic and exit
[2020-10-25T15:36:36.761 UTC] [debug] done with backend process
25510: EXIT 1

so we need to add "cap-cfpc=broken,cap-sbbc=broken,cap-ibs=broken" to the test setting QEMUMACHINE in case it is not already included:

    # newer qemu needs safe cache capability level quirk settings
    # https://progress.opensuse.org/issues/75259
    my $caps = ',cap-cfpc=broken,cap-sbbc=broken,cap-ibs=broken';
    $vars->{QEMUMACHINE} .= $caps if $self->{qemu_version} >= '4' && $vars->{QEMUMACHINE} !~ /$caps/;

I hotpatched that now on power8.

https://openqa.opensuse.org/tests/1448862 passed

I called ./openqa-monitor-incompletes | ./openqa-label-known-issues from github.com/os-autoinst/scripts/ after I added the "auto_review" marker in the ticket subject line. Many ppc64le jobs are running now. Did ssh -J o3 root@power8 "cat /usr/lib/os-autoinst/backend/qemu.pm" > backend/qemu.pm to copy over to local working copy.

Created PR https://github.com/os-autoinst/os-autoinst/pull/1554

PR is merged and deployed on power8, tests are fine on power8, hotfix was replaced.