action #73375
Updated by okurz over 3 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).