action #73375
Updated by okurz over 2 years ago
# observation
The real error messages are only found within the worker log despite the fact that is was apparently possible to pass "api failure":
```
Okt 13 17:59:28 openqaworker4 worker[1908]: [info] Running on openqaworker4:7 (Linux 4.12.14-lp151.28.71-default #1 SMP Thu Oct 8 12:40:48 UTC 2020 (dda1832) x86_64)
Okt 13 17:59:28 openqaworker4 worker[1908]: [info] Downloading openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256, request #127800 sent to Cache Service
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] Download of openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256 processed:
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Cache size of "/var/lib/openqa/cache" is 49GiB, with limit 50GiB
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Downloading "openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" from "http://openqa1-opensuse/tests/1432537/asset/other/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256"
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Size of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" is 122 Byte, with ETag ""7a-5b17554ac6ab0""
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Download of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" successful, new cache size is 49GiB
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] Downloading openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso, request #127801 sent to Cache Service
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] Download of openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso processed:
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Cache size of "/var/lib/openqa/cache" is 49GiB, with limit 50GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Downloading "openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" from "http://openqa1-opensuse/tests/1432537/asset/iso/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso"
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Cache size 49GiB + needed 876MiB exceeds limit of 50GiB, purging least used assets
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Purging "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Staging:M-Kubic-DVD-x86_64-Build163.5-Media.iso.sha256" because we need space for new assets, reclaiming 113 Byte
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Purging "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Staging:M-Kubic-DVD-x86_64-Build163.5-Media.iso" because we need space for new assets, reclaiming 1.6GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Size of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" is 876MiB, with ETag ""36ba0000-5b174fdec5580""
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Download of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" successful, new cache size is 49GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] Rsync from 'rsync://openqa1-opensuse/tests' to '/var/lib/openqa/cache/openqa1-opensuse', request #127802 sent to Cache Service
... Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Output of rsync:
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] [#127802] Calling: rsync -avHP rsync://openqa1-opensuse/tests/ --delete /var/lib/openqa/cache/openqa1-opensuse/tests/
Okt 13 18:00:04 openqaworker4 worker[1908]: receiving incremental file list
Okt 13 18:00:04 openqaworker4 worker[1908]: obs/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: obs/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/needles/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/needles/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/products/opensuse/needles/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/products/opensuse/needles/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [117B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: sent 1,789 bytes received 1,009,792 bytes 674,387.33 bytes/sec
Okt 13 18:00:04 openqaworker4 worker[1908]: total size is 4,330,139,739 speedup is 4,280.57
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Finished to rsync tests
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Preparing cgroup to start isotovideo
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Using cgroup /sys/fs/cgroup/systemd/openqa.slice/openqa-worker.slice/openqa-worker@7.service/1432537
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Starting isotovideo container
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] isotovideo has been started (PID: 32675)
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] 32675: WORKING 1432537
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Isotovideo exit status: 0
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] +++ worker notes +++
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] End time: 2020-10-13 17:16:52
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Result: done
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Uploading ncurses-dmesg.log
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Uploading ncurses-ip-addr-show.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-journal.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-loadavg.txt
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-plasma5_configs.tar.bz2
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-problem_detection_logs.tar.xz
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-psaxf.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-sddm_session.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-solverTestCase.tar.bz2
Okt 13 19:16:58 openqaworker4 worker[1908]: [info] Uploading ncurses-sysconfig.tar.bz2
Okt 13 19:16:58 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl_status.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl_unit-files.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-dmesg.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-journal.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-loadavg.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-plasma5_configs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-psaxf.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sddm_session.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sysconfig.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading system_state-stats_during_installation.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-info.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-y2logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-journal.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-loadavg.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-plasma5_configs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-psaxf.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sddm_session.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sysconfig.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading system_state-stats_during_installation.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-info.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-y2logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-zypper.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-dmesg.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-ip-addr-show.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-journal.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-loadavg.txt
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-plasma5_configs.tar.bz2
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-problem_detection_logs.tar.xz
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-psaxf.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-sddm_session.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-solverTestCase.tar.bz2
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-sysconfig.tar.bz2
Okt 13 19:17:09 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl.log
Okt 13 19:17:09 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl_status.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl_unit-files.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-Xlogs.system.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-zypper.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_log-dmesg.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_log-ip-addr-show.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-journal.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-loadavg.txt
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-plasma5_configs.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-problem_detection_logs.tar.xz
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-psaxf.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-sddm_session.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-solverTestCase.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-sysconfig.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl_status.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl_unit-files.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-Xlogs.system.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-zypper.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-dmesg.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-journal.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-loadavg.txt
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-plasma5_configs.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-psaxf.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-sddm_session.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-sysconfig.tar.bz2
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading zypper_ref-Xlogs.system.log
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading zypper_ref-zypper.log
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading video.ogv
Okt 13 19:17:17 openqaworker4 worker[1908]: [info] Uploading vars.json
Okt 13 19:17:22 openqaworker4 worker[1908]: [info] Uploading autoinst-log.txt
Okt 13 19:17:22 openqaworker4 worker[1908]: [info] Uploading worker-log.txt
Okt 13 19:17:32 openqaworker4 worker[1908]: [error] Error uploading worker-log.txt: connection error: Can't connect: Temporary failure in name resolution
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:17:34 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1005, no reason - trying again in 10 seconds
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:27:34 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:36:05 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:44:25 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:52:55 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
```
(https://openqa.opensuse.org/tests/1432537)
### suggestions, further information
* This ticket already causes auto-review to automatically restart such jobs. Maybe it would make sense if openQA would restart jobs in case of API failures on its own.
* Of course it would be nice if the worker would pass the exact error message and not just "api failure".
* Considering the log there *might* be a bug in the retry logic (although it is intended that the worker re-registers in case of API errors).
The real error messages are only found within the worker log despite the fact that is was apparently possible to pass "api failure":
```
Okt 13 17:59:28 openqaworker4 worker[1908]: [info] Running on openqaworker4:7 (Linux 4.12.14-lp151.28.71-default #1 SMP Thu Oct 8 12:40:48 UTC 2020 (dda1832) x86_64)
Okt 13 17:59:28 openqaworker4 worker[1908]: [info] Downloading openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256, request #127800 sent to Cache Service
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] Download of openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256 processed:
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Cache size of "/var/lib/openqa/cache" is 49GiB, with limit 50GiB
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Downloading "openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" from "http://openqa1-opensuse/tests/1432537/asset/other/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256"
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Size of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" is 122 Byte, with ETag ""7a-5b17554ac6ab0""
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] [#127800] Download of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso.sha256" successful, new cache size is 49GiB
Okt 13 17:59:39 openqaworker4 worker[1908]: [info] Downloading openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso, request #127801 sent to Cache Service
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] Download of openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso processed:
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Cache size of "/var/lib/openqa/cache" is 49GiB, with limit 50GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Downloading "openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" from "http://openqa1-opensuse/tests/1432537/asset/iso/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso"
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Cache size 49GiB + needed 876MiB exceeds limit of 50GiB, purging least used assets
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Purging "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Staging:M-Kubic-DVD-x86_64-Build163.5-Media.iso.sha256" because we need space for new assets, reclaiming 113 Byte
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Purging "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Staging:M-Kubic-DVD-x86_64-Build163.5-Media.iso" because we need space for new assets, reclaiming 1.6GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Size of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" is 876MiB, with ETag ""36ba0000-5b174fdec5580""
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] [#127801] Download of "/var/lib/openqa/cache/openqa1-opensuse/openSUSE-Jump-15.2.1-KDE-Live-x86_64-Build2.8-Media.iso" successful, new cache size is 49GiB
Okt 13 17:59:59 openqaworker4 worker[1908]: [info] Rsync from 'rsync://openqa1-opensuse/tests' to '/var/lib/openqa/cache/openqa1-opensuse', request #127802 sent to Cache Service
... Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Output of rsync:
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] [#127802] Calling: rsync -avHP rsync://openqa1-opensuse/tests/ --delete /var/lib/openqa/cache/openqa1-opensuse/tests/
Okt 13 18:00:04 openqaworker4 worker[1908]: receiving incremental file list
Okt 13 18:00:04 openqaworker4 worker[1908]: obs/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: obs/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/needles/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: openqa/needles/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [116B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/products/opensuse/needles/.git/
Okt 13 18:00:04 openqaworker4 worker[1908]: opensuse/products/opensuse/needles/.git/FETCH_HEAD
Okt 13 18:00:04 openqaworker4 worker[1908]: [117B blob data]
Okt 13 18:00:04 openqaworker4 worker[1908]: sent 1,789 bytes received 1,009,792 bytes 674,387.33 bytes/sec
Okt 13 18:00:04 openqaworker4 worker[1908]: total size is 4,330,139,739 speedup is 4,280.57
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Finished to rsync tests
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Preparing cgroup to start isotovideo
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Using cgroup /sys/fs/cgroup/systemd/openqa.slice/openqa-worker.slice/openqa-worker@7.service/1432537
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] Starting isotovideo container
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] isotovideo has been started (PID: 32675)
Okt 13 18:00:04 openqaworker4 worker[1908]: [info] 32675: WORKING 1432537
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Isotovideo exit status: 0
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] +++ worker notes +++
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] End time: 2020-10-13 17:16:52
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Result: done
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Uploading ncurses-dmesg.log
Okt 13 19:16:52 openqaworker4 worker[1908]: [info] Uploading ncurses-ip-addr-show.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-journal.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-loadavg.txt
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-plasma5_configs.tar.bz2
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-problem_detection_logs.tar.xz
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-psaxf.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-sddm_session.log
Okt 13 19:16:57 openqaworker4 worker[1908]: [info] Uploading ncurses-solverTestCase.tar.bz2
Okt 13 19:16:58 openqaworker4 worker[1908]: [info] Uploading ncurses-sysconfig.tar.bz2
Okt 13 19:16:58 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl_status.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-systemctl_unit-files.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading ncurses-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-dmesg.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-journal.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-loadavg.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-plasma5_configs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-psaxf.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sddm_session.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sysconfig.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading system_state-stats_during_installation.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-info.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-y2logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-journal.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-loadavg.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-plasma5_configs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-psaxf.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sddm_session.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-sysconfig.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-Xlogs.system.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading sshd-zypper.log
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading system_state-stats_during_installation.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-info.txt
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading textinfo-logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-y2logs.tar.bz2
Okt 13 19:17:03 openqaworker4 worker[1908]: [info] Uploading yast2_lan-zypper.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-dmesg.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-ip-addr-show.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-journal.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-loadavg.txt
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-plasma5_configs.tar.bz2
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-problem_detection_logs.tar.xz
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-psaxf.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-sddm_session.log
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-solverTestCase.tar.bz2
Okt 13 19:17:04 openqaworker4 worker[1908]: [info] Uploading zypper_in-sysconfig.tar.bz2
Okt 13 19:17:09 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl.log
Okt 13 19:17:09 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl_status.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-systemctl_unit-files.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-Xlogs.system.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_in-zypper.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_log-dmesg.log
Okt 13 19:17:14 openqaworker4 worker[1908]: [info] Uploading zypper_log-ip-addr-show.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-journal.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-loadavg.txt
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-plasma5_configs.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-problem_detection_logs.tar.xz
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-psaxf.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-sddm_session.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-solverTestCase.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-sysconfig.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl_status.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-systemctl_unit-files.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-Xlogs.system.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_log-zypper.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-dmesg.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-journal.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-loadavg.txt
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-plasma5_configs.tar.bz2
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-psaxf.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-sddm_session.log
Okt 13 19:17:15 openqaworker4 worker[1908]: [info] Uploading zypper_ref-sysconfig.tar.bz2
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading zypper_ref-Xlogs.system.log
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading zypper_ref-zypper.log
Okt 13 19:17:16 openqaworker4 worker[1908]: [info] Uploading video.ogv
Okt 13 19:17:17 openqaworker4 worker[1908]: [info] Uploading vars.json
Okt 13 19:17:22 openqaworker4 worker[1908]: [info] Uploading autoinst-log.txt
Okt 13 19:17:22 openqaworker4 worker[1908]: [info] Uploading worker-log.txt
Okt 13 19:17:32 openqaworker4 worker[1908]: [error] Error uploading worker-log.txt: connection error: Can't connect: Temporary failure in name resolution
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:17:34 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:17:34 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1005, no reason - trying again in 10 seconds
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:17:44 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:27:34 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:27:44 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:36:05 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:36:15 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:44:25 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:44:35 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
Okt 13 19:52:55 openqaworker4 worker[1908]: [warn] Websocket connection to http://openqa1-opensuse/api/v1/ws/170 finished by remote side with code 1006, no reason - trying again in 10 seconds
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Registering with openQA http://openqa1-opensuse
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Establishing ws connection via ws://openqa1-opensuse/api/v1/ws/170
Okt 13 19:53:05 openqaworker4 worker[1908]: [info] Registered and connected via websockets with openQA host http://openqa1-opensuse and worker ID 170
```
(https://openqa.opensuse.org/tests/1432537)
### suggestions, further information
* This ticket already causes auto-review to automatically restart such jobs. Maybe it would make sense if openQA would restart jobs in case of API failures on its own.
* Of course it would be nice if the worker would pass the exact error message and not just "api failure".
* Considering the log there *might* be a bug in the retry logic (although it is intended that the worker re-registers in case of API errors).