2026-03-01 00:24:58.374791 | Job console starting... 2026-03-01 00:24:58.387209 | Updating repositories 2026-03-01 00:24:58.566490 | Preparing job workspace 2026-03-01 00:25:02.458019 | Running Ansible setup... 2026-03-01 00:25:10.167899 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-01 00:25:10.854121 | 2026-03-01 00:25:10.854265 | PLAY [localhost] 2026-03-01 00:25:10.863061 | 2026-03-01 00:25:10.863144 | TASK [Gathering Facts] 2026-03-01 00:25:11.940297 | localhost | ok 2026-03-01 00:25:11.969001 | 2026-03-01 00:25:11.969129 | TASK [Setup log path fact] 2026-03-01 00:25:11.992591 | localhost | ok 2026-03-01 00:25:12.012406 | 2026-03-01 00:25:12.012520 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-01 00:25:12.054656 | localhost | ok 2026-03-01 00:25:12.067067 | 2026-03-01 00:25:12.067186 | TASK [emit-job-header : Print job information] 2026-03-01 00:25:12.119333 | # Job Information 2026-03-01 00:25:12.119536 | Ansible Version: 2.15.12 2026-03-01 00:25:12.119580 | Job: ansible-test-sanity-docker-devel 2026-03-01 00:25:12.119610 | Pipeline: periodic 2026-03-01 00:25:12.119635 | Executor: ze03.softwarefactory-project.io 2026-03-01 00:25:12.119660 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-03-01 00:25:12.119689 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/220/ansible/22042c7962b746cbaf8d48151dad5875/ 2026-03-01 00:25:12.119715 | Event ID: 9a68ce5367a74382a3f0efb74cca8a21 2026-03-01 00:25:12.125455 | 2026-03-01 00:25:12.125542 | LOOP [emit-job-header : Print node information] 2026-03-01 00:25:12.231846 | localhost | ok: 2026-03-01 00:25:12.232083 | localhost | # Node Information 2026-03-01 00:25:12.232111 | localhost | Inventory Hostname: controller 2026-03-01 00:25:12.232131 | localhost | Hostname: np0005634392 2026-03-01 00:25:12.232150 | localhost | Username: zuul 2026-03-01 00:25:12.232174 | localhost | Distro: Fedora 37 2026-03-01 00:25:12.232193 | localhost | Provider: ansible-vexxhost-ams1 2026-03-01 00:25:12.232212 | localhost | Region: ams1 2026-03-01 00:25:12.232236 | localhost | Label: ansible-fedora-37-1vcpu 2026-03-01 00:25:12.232265 | localhost | Product Name: OpenStack Nova 2026-03-01 00:25:12.232297 | localhost | Interface IP: 38.129.16.244 2026-03-01 00:25:12.241298 | 2026-03-01 00:25:12.241374 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-01 00:25:12.662978 | localhost -> localhost | changed 2026-03-01 00:25:12.675003 | 2026-03-01 00:25:12.675143 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-01 00:25:13.572084 | localhost -> localhost | changed 2026-03-01 00:25:13.613675 | 2026-03-01 00:25:13.613833 | PLAY [all:!appliance*] 2026-03-01 00:25:13.644819 | 2026-03-01 00:25:13.644911 | TASK [include_role : start-zuul-console] 2026-03-01 00:25:13.667712 | controller | ok 2026-03-01 00:25:13.686907 | 2026-03-01 00:25:13.686999 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-03-01 00:25:14.733908 | controller | ok 2026-03-01 00:25:14.759504 | 2026-03-01 00:25:14.759646 | TASK [use-our-mirror : Retrieve the IP address] 2026-03-01 00:25:19.313793 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-03-01 00:25:19.327818 | 2026-03-01 00:25:19.327956 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-03-01 00:25:19.700223 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.709125 | 2026-03-01 00:25:19.709222 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-03-01 00:25:19.744702 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.753504 | 2026-03-01 00:25:19.753591 | TASK [use-our-mirror : Create the podman configuration directory] 2026-03-01 00:25:19.778278 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.786772 | 2026-03-01 00:25:19.786861 | TASK [use-our-mirror : Copy the podman configuration] 2026-03-01 00:25:19.812064 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.820858 | 2026-03-01 00:25:19.820962 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-03-01 00:25:19.836412 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.844616 | 2026-03-01 00:25:19.844776 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-03-01 00:25:19.868935 | controller | skipping: Conditional result was False 2026-03-01 00:25:19.884823 | 2026-03-01 00:25:19.884965 | TASK [Disable Fedora Modular] 2026-03-01 00:25:21.198623 | controller | changed 2026-03-01 00:25:21.212878 | 2026-03-01 00:25:21.213020 | TASK [Enable EPEL] 2026-03-01 00:25:21.239698 | controller | skipping: Conditional result was False 2026-03-01 00:25:21.289631 | 2026-03-01 00:25:21.289799 | TASK [Register the RHEL node] 2026-03-01 00:25:21.666094 | 2026-03-01 00:25:21.666227 | TASK [Show the subscription-manager status] 2026-03-01 00:25:22.032158 | controller | skipping: Conditional result was False 2026-03-01 00:25:22.038582 | 2026-03-01 00:25:22.038646 | TASK [Enable EPEL on RHEL] 2026-03-01 00:25:22.411784 | controller | skipping: Conditional result was False 2026-03-01 00:25:22.418040 | 2026-03-01 00:25:22.418109 | TASK [Install git and tox] 2026-03-01 00:27:33.922382 | controller | changed 2026-03-01 00:27:33.949595 | 2026-03-01 00:27:33.949855 | TASK [include_role : prepare-workspace] 2026-03-01 00:27:33.984129 | controller | ok 2026-03-01 00:27:34.016028 | 2026-03-01 00:27:34.016183 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-01 00:27:34.888827 | controller | ok 2026-03-01 00:27:34.902651 | 2026-03-01 00:27:34.902839 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-01 00:27:50.831960 | controller | Output suppressed because no_log was given 2026-03-01 00:27:50.842494 | 2026-03-01 00:27:50.842554 | TASK [include_role : prepare-workspace-openshift] 2026-03-01 00:27:50.857414 | controller | skipping: Conditional result was False 2026-03-01 00:27:50.881549 | 2026-03-01 00:27:50.881639 | PLAY [all:!appliance] 2026-03-01 00:27:50.897651 | 2026-03-01 00:27:50.897797 | TASK [Run add-build-sshkey role (RSA)] 2026-03-01 00:27:50.930159 | controller | ok 2026-03-01 00:27:50.947529 | 2026-03-01 00:27:50.947635 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-01 00:27:51.199748 | controller -> localhost | ok 2026-03-01 00:27:51.206669 | 2026-03-01 00:27:51.206750 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-01 00:27:51.237567 | controller | ok 2026-03-01 00:27:51.258670 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-01 00:27:51.266606 | 2026-03-01 00:27:51.266738 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-01 00:27:51.744666 | controller -> localhost | Generating public/private rsa key pair. 2026-03-01 00:27:51.744953 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_rsa. 2026-03-01 00:27:51.745000 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_rsa.pub. 2026-03-01 00:27:51.745036 | controller -> localhost | The key fingerprint is: 2026-03-01 00:27:51.745068 | controller -> localhost | SHA256:+JpYdHkOicooQOlxPOtrAxPNi31Nv7amCewu3ug0F7M zuul-build-sshkey 2026-03-01 00:27:51.745101 | controller -> localhost | The key's randomart image is: 2026-03-01 00:27:51.745133 | controller -> localhost | +---[RSA 2048]----+ 2026-03-01 00:27:51.745164 | controller -> localhost | | | 2026-03-01 00:27:51.745196 | controller -> localhost | | o | 2026-03-01 00:27:51.745227 | controller -> localhost | | +o+ | 2026-03-01 00:27:51.745256 | controller -> localhost | |o.ooo + o | 2026-03-01 00:27:51.745283 | controller -> localhost | |..+..o* S . | 2026-03-01 00:27:51.745323 | controller -> localhost | |.+.=.+++ = | 2026-03-01 00:27:51.745355 | controller -> localhost | |. +++E. . o | 2026-03-01 00:27:51.745384 | controller -> localhost | | ..+Bo.o.+ | 2026-03-01 00:27:51.745412 | controller -> localhost | | +==+oo+.. | 2026-03-01 00:27:51.745445 | controller -> localhost | +----[SHA256]-----+ 2026-03-01 00:27:51.745533 | controller -> localhost | ok: Runtime: 0:00:00.047966 2026-03-01 00:27:51.758075 | 2026-03-01 00:27:51.758202 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-01 00:27:51.792833 | controller | ok 2026-03-01 00:27:51.808265 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-01 00:27:51.817966 | 2026-03-01 00:27:51.818052 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-01 00:27:51.841813 | controller | skipping: Conditional result was False 2026-03-01 00:27:51.848678 | 2026-03-01 00:27:51.848784 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-01 00:27:52.922637 | controller | changed 2026-03-01 00:27:52.935806 | 2026-03-01 00:27:52.936033 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-01 00:27:53.621009 | controller | ok 2026-03-01 00:27:53.635252 | 2026-03-01 00:27:53.635406 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-01 00:27:56.703666 | controller | changed 2026-03-01 00:27:56.717400 | 2026-03-01 00:27:56.717578 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-01 00:27:59.847403 | controller | changed 2026-03-01 00:27:59.860381 | 2026-03-01 00:27:59.860530 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-01 00:27:59.888489 | controller | skipping: Conditional result was False 2026-03-01 00:27:59.899533 | 2026-03-01 00:27:59.899708 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-01 00:28:00.278867 | controller -> localhost | changed 2026-03-01 00:28:00.291269 | 2026-03-01 00:28:00.291362 | TASK [add-build-sshkey : Add back temp key] 2026-03-01 00:28:00.581019 | controller -> localhost | Identity added: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_rsa (zuul-build-sshkey) 2026-03-01 00:28:00.581322 | controller -> localhost | ok: Runtime: 0:00:00.011655 2026-03-01 00:28:00.591418 | 2026-03-01 00:28:00.591610 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-01 00:28:01.534906 | controller | ok 2026-03-01 00:28:01.550363 | 2026-03-01 00:28:01.550554 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-01 00:28:01.596648 | controller | skipping: Conditional result was False 2026-03-01 00:28:01.613359 | 2026-03-01 00:28:01.613512 | TASK [Run add-build-sshkey role (ECDSA)] 2026-03-01 00:28:01.647842 | controller | ok 2026-03-01 00:28:01.673704 | 2026-03-01 00:28:01.673889 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-01 00:28:01.923926 | controller -> localhost | ok 2026-03-01 00:28:01.939987 | 2026-03-01 00:28:01.940151 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-01 00:28:01.970601 | controller | ok 2026-03-01 00:28:01.993192 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-01 00:28:02.002305 | 2026-03-01 00:28:02.002410 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-01 00:28:02.355547 | controller -> localhost | Generating public/private ecdsa key pair. 2026-03-01 00:28:02.355744 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_ecdsa. 2026-03-01 00:28:02.355783 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_ecdsa.pub. 2026-03-01 00:28:02.355814 | controller -> localhost | The key fingerprint is: 2026-03-01 00:28:02.355835 | controller -> localhost | SHA256:3GegDDeXVR7CpZMWBLLQVCIyP/3IdE2CqV83knhW0J8 zuul-build-sshkey 2026-03-01 00:28:02.355854 | controller -> localhost | The key's randomart image is: 2026-03-01 00:28:02.355872 | controller -> localhost | +---[ECDSA 521]---+ 2026-03-01 00:28:02.355890 | controller -> localhost | | o oo++=**o+ | 2026-03-01 00:28:02.355908 | controller -> localhost | | + +++ *+* . | 2026-03-01 00:28:02.355934 | controller -> localhost | | +.*.=o*... | 2026-03-01 00:28:02.355951 | controller -> localhost | | .O.O*oo.E | 2026-03-01 00:28:02.355968 | controller -> localhost | | .S+ooo. | 2026-03-01 00:28:02.355984 | controller -> localhost | | . o | 2026-03-01 00:28:02.356002 | controller -> localhost | | | 2026-03-01 00:28:02.356019 | controller -> localhost | | | 2026-03-01 00:28:02.356035 | controller -> localhost | | | 2026-03-01 00:28:02.356052 | controller -> localhost | +----[SHA256]-----+ 2026-03-01 00:28:02.356106 | controller -> localhost | ok: Runtime: 0:00:00.014210 2026-03-01 00:28:02.392442 | 2026-03-01 00:28:02.392585 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-01 00:28:02.413494 | controller | ok 2026-03-01 00:28:02.421373 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-01 00:28:02.430069 | 2026-03-01 00:28:02.430133 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-01 00:28:02.444318 | controller | skipping: Conditional result was False 2026-03-01 00:28:02.452260 | 2026-03-01 00:28:02.452347 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-01 00:28:03.356174 | controller | changed 2026-03-01 00:28:03.368878 | 2026-03-01 00:28:03.369013 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-01 00:28:04.042263 | controller | ok 2026-03-01 00:28:04.056391 | 2026-03-01 00:28:04.056534 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-01 00:28:07.090865 | controller | changed 2026-03-01 00:28:07.104687 | 2026-03-01 00:28:07.104990 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-01 00:28:10.147553 | controller | changed 2026-03-01 00:28:10.160770 | 2026-03-01 00:28:10.160915 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-01 00:28:10.188550 | controller | skipping: Conditional result was False 2026-03-01 00:28:10.203285 | 2026-03-01 00:28:10.203424 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-01 00:28:10.506047 | controller -> localhost | changed 2026-03-01 00:28:10.517650 | 2026-03-01 00:28:10.517719 | TASK [add-build-sshkey : Add back temp key] 2026-03-01 00:28:10.851758 | controller -> localhost | Identity added: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/22042c7962b746cbaf8d48151dad5875_id_ecdsa (zuul-build-sshkey) 2026-03-01 00:28:10.852295 | controller -> localhost | ok: Runtime: 0:00:00.013431 2026-03-01 00:28:10.868509 | 2026-03-01 00:28:10.868666 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-01 00:28:11.577968 | controller | ok 2026-03-01 00:28:11.589793 | 2026-03-01 00:28:11.589930 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-01 00:28:11.637581 | controller | skipping: Conditional result was False 2026-03-01 00:28:11.661863 | 2026-03-01 00:28:11.662003 | TASK [include_role : remove-zuul-sshkey] 2026-03-01 00:28:11.689207 | controller | skipping: Conditional result was False 2026-03-01 00:28:11.703394 | 2026-03-01 00:28:11.703532 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-01 00:28:12.388524 | controller | ok: "logs" 2026-03-01 00:28:12.389098 | controller | ok: All items complete 2026-03-01 00:28:12.389180 | 2026-03-01 00:28:13.026299 | controller | ok: "artifacts" 2026-03-01 00:28:13.653014 | controller | ok: "docs" 2026-03-01 00:28:13.679450 | 2026-03-01 00:28:13.679668 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-01 00:28:14.390990 | controller | changed: "logs" 2026-03-01 00:28:15.026490 | controller | changed: "artifacts" 2026-03-01 00:28:15.651635 | controller | changed: "docs" 2026-03-01 00:28:15.710345 | 2026-03-01 00:28:15.710509 | PLAY RECAP 2026-03-01 00:28:15.710573 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-03-01 00:28:15.710608 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-01 00:28:15.710632 | 2026-03-01 00:28:15.837777 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-01 00:28:15.839544 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-01 00:28:16.540625 | 2026-03-01 00:28:16.540782 | PLAY [all] 2026-03-01 00:28:16.564641 | 2026-03-01 00:28:16.564807 | TASK [Install binary dependencies] 2026-03-01 00:28:16.638536 | controller | ok 2026-03-01 00:28:16.666474 | 2026-03-01 00:28:16.666602 | TASK [bindep : Include find tasks] 2026-03-01 00:28:16.710322 | controller | ok 2026-03-01 00:28:16.718496 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-03-01 00:28:16.725826 | 2026-03-01 00:28:16.725974 | TASK [bindep : Look for bindep.txt] 2026-03-01 00:28:17.677648 | controller | ok 2026-03-01 00:28:17.691425 | 2026-03-01 00:28:17.691611 | TASK [bindep : Define bindep_file fact] 2026-03-01 00:28:17.720638 | controller | skipping: Conditional result was False 2026-03-01 00:28:17.737258 | 2026-03-01 00:28:17.737446 | TASK [bindep : Look for other-requirements.txt] 2026-03-01 00:28:18.413150 | controller | ok 2026-03-01 00:28:18.426967 | 2026-03-01 00:28:18.427120 | TASK [bindep : Define bindep_file fact] 2026-03-01 00:28:18.466119 | controller | skipping: Conditional result was False 2026-03-01 00:28:18.481749 | 2026-03-01 00:28:18.481978 | TASK [bindep : Look for bindep fallback file] 2026-03-01 00:28:18.521850 | controller | skipping: Conditional result was False 2026-03-01 00:28:18.536882 | 2026-03-01 00:28:18.537035 | TASK [bindep : Define bindep_file fact] 2026-03-01 00:28:18.575871 | controller | skipping: Conditional result was False 2026-03-01 00:28:18.590180 | 2026-03-01 00:28:18.590331 | TASK [bindep : Include bindep tasks] 2026-03-01 00:28:18.628865 | controller | skipping: Conditional result was False 2026-03-01 00:28:18.643683 | 2026-03-01 00:28:18.643861 | TASK [bindep : Include install tasks] 2026-03-01 00:28:18.682219 | controller | skipping: Conditional result was False 2026-03-01 00:28:18.697658 | 2026-03-01 00:28:18.697918 | LOOP [bindep : Include package tasks] 2026-03-01 00:28:18.788582 | 2026-03-01 00:28:18.789142 | TASK [Run test-setup role] 2026-03-01 00:28:18.821562 | controller | ok 2026-03-01 00:28:18.853047 | 2026-03-01 00:28:18.853150 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-03-01 00:28:19.586009 | controller | ok 2026-03-01 00:28:19.599887 | 2026-03-01 00:28:19.600027 | TASK [test-setup : Run tools/test-setup.sh] 2026-03-01 00:28:19.982536 | controller | skipping: Conditional result was False 2026-03-01 00:28:20.038508 | 2026-03-01 00:28:20.038676 | PLAY RECAP 2026-03-01 00:28:20.038762 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-01 00:28:20.038799 | 2026-03-01 00:28:20.203770 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-01 00:28:20.204987 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-01 00:28:20.796213 | 2026-03-01 00:28:20.796380 | PLAY [controller] 2026-03-01 00:28:20.817977 | 2026-03-01 00:28:20.818096 | TASK [Create the /root directory] 2026-03-01 00:28:21.974129 | controller | ok 2026-03-01 00:28:21.988241 | 2026-03-01 00:28:21.988396 | TASK [Install glibc-langpack-en] 2026-03-01 00:28:31.033392 | controller | ok: Nothing to do 2026-03-01 00:28:31.046440 | 2026-03-01 00:28:31.046604 | TASK [Ensure controller directory exists] 2026-03-01 00:28:31.912041 | controller | changed 2026-03-01 00:28:31.924614 | 2026-03-01 00:28:31.924800 | TASK [Install container runtime] 2026-03-01 00:28:32.005883 | controller | ok 2026-03-01 00:28:32.063745 | 2026-03-01 00:28:32.063883 | LOOP [ensure-podman : Find distribution installation] 2026-03-01 00:28:32.107646 | controller | ok: "/var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-03-01 00:28:32.126391 | controller | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-03-01 00:28:32.141010 | 2026-03-01 00:28:32.141157 | TASK [ensure-podman : Install podman (RedHat)] 2026-03-01 00:31:03.223018 | controller | changed 2026-03-01 00:31:03.240053 | 2026-03-01 00:31:03.240219 | TASK [ensure-podman : Fetch podman version] 2026-03-01 00:31:04.828468 | controller | Client: Podman Engine 2026-03-01 00:31:04.863839 | controller | Version: 4.6.2 2026-03-01 00:31:04.863900 | controller | API Version: 4.6.2 2026-03-01 00:31:04.863910 | controller | Go Version: go1.19.12 2026-03-01 00:31:04.863930 | controller | Built: Mon Aug 28 19:38:31 2023 2026-03-01 00:31:04.863938 | controller | OS/Arch: linux/amd64 2026-03-01 00:31:05.121032 | controller | ok: Runtime: 0:00:00.288777 2026-03-01 00:31:05.135319 | 2026-03-01 00:31:05.135510 | TASK [ensure-podman : Print podman version installed] 2026-03-01 00:31:05.174435 | Podman version: Client: Podman Engine 2026-03-01 00:31:05.174704 | Version: 4.6.2 2026-03-01 00:31:05.174819 | API Version: 4.6.2 2026-03-01 00:31:05.174869 | Go Version: go1.19.12 2026-03-01 00:31:05.174911 | Built: Mon Aug 28 19:38:31 2023 2026-03-01 00:31:05.174959 | OS/Arch: linux/amd64 2026-03-01 00:31:05.187959 | 2026-03-01 00:31:05.188105 | TASK [ensure-podman : Validate podman engine] 2026-03-01 00:31:05.557402 | controller | skipping: Conditional result was False 2026-03-01 00:31:05.565982 | 2026-03-01 00:31:05.566099 | TASK [ensure-podman : Set up docker compatability socket] 2026-03-01 00:31:05.591771 | controller | skipping: Conditional result was False 2026-03-01 00:31:05.617196 | 2026-03-01 00:31:05.617391 | TASK [Ensure python3.8 is present] 2026-03-01 00:31:05.635334 | controller | skipping: Conditional result was False 2026-03-01 00:31:05.646096 | 2026-03-01 00:31:05.646235 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-03-01 00:31:05.670828 | controller | ok 2026-03-01 00:31:05.699183 | 2026-03-01 00:31:05.699357 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-03-01 00:31:09.356580 | controller | ok: Nothing to do 2026-03-01 00:31:09.371169 | 2026-03-01 00:31:09.371318 | TASK [our-ensure-python : Also install python3-devel] 2026-03-01 00:31:25.056572 | controller | changed 2026-03-01 00:31:25.082713 | 2026-03-01 00:31:25.082893 | TASK [Run ensure-virtualenv role] 2026-03-01 00:31:25.112370 | controller | ok 2026-03-01 00:31:25.149915 | 2026-03-01 00:31:25.150049 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-03-01 00:31:25.974424 | controller | /usr/bin/virtualenv 2026-03-01 00:31:26.508213 | controller | ok: Runtime: 0:00:00.007223 2026-03-01 00:31:26.517326 | 2026-03-01 00:31:26.517436 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-03-01 00:31:26.554988 | controller | skipping: Conditional result was False 2026-03-01 00:31:26.555449 | controller | ok: All items complete 2026-03-01 00:31:26.555509 | 2026-03-01 00:31:26.579107 | 2026-03-01 00:31:26.579263 | TASK [Find the full path of the Python interpreter] 2026-03-01 00:31:27.389827 | controller | /usr/bin/python3 2026-03-01 00:31:27.950042 | controller | ok 2026-03-01 00:31:27.962974 | 2026-03-01 00:31:27.963237 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-03-01 00:31:29.792689 | controller | created virtual environment CPython3.11.0.final.0-64 in 846ms 2026-03-01 00:31:29.902195 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-03-01 00:31:29.902964 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-03-01 00:31:29.903253 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-03-01 00:31:29.903973 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-03-01 00:31:30.333871 | controller | changed 2026-03-01 00:31:30.347191 | 2026-03-01 00:31:30.347327 | TASK [Set selinux package] 2026-03-01 00:31:30.387436 | controller | ok 2026-03-01 00:31:30.398631 | 2026-03-01 00:31:30.398926 | TASK [Set selinux package (Fedora)] 2026-03-01 00:31:30.448824 | controller | ok 2026-03-01 00:31:30.460319 | 2026-03-01 00:31:30.460452 | TASK [Install selinux into virtualenv] 2026-03-01 00:31:33.797776 | controller | Collecting selinux-please-lie-to-me 2026-03-01 00:31:33.953187 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-03-01 00:31:34.541590 | controller | Collecting setuptools<50.0.0 2026-03-01 00:31:34.549043 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-03-01 00:31:34.616331 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 12.9 MB/s eta 0:00:00 2026-03-01 00:31:34.823548 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-03-01 00:31:34.823852 | controller | Attempting uninstall: setuptools 2026-03-01 00:31:34.828400 | controller | Found existing installation: setuptools 62.6.0 2026-03-01 00:31:34.943132 | controller | Uninstalling setuptools-62.6.0: 2026-03-01 00:31:34.958487 | controller | Successfully uninstalled setuptools-62.6.0 2026-03-01 00:31:35.741739 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-03-01 00:31:35.949899 | controller | 2026-03-01 00:31:36.229983 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-01 00:31:36.230059 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-01 00:31:36.848232 | controller | ok: Runtime: 0:00:04.916321 2026-03-01 00:31:36.864186 | 2026-03-01 00:31:36.864396 | TASK [Install pytest-forked into virtualenv] 2026-03-01 00:31:38.364099 | controller | Collecting pytest-forked 2026-03-01 00:31:38.442927 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-03-01 00:31:38.512602 | controller | Collecting py 2026-03-01 00:31:38.517141 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-03-01 00:31:38.553066 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.8 MB/s eta 0:00:00 2026-03-01 00:31:38.752265 | controller | Collecting pytest>=3.10 2026-03-01 00:31:38.759742 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-03-01 00:31:38.783770 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.1 MB/s eta 0:00:00 2026-03-01 00:31:38.863747 | controller | Collecting iniconfig>=1.0.1 2026-03-01 00:31:38.872783 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-03-01 00:31:38.961929 | controller | Collecting packaging>=22 2026-03-01 00:31:38.966422 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-03-01 00:31:38.984140 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 4.5 MB/s eta 0:00:00 2026-03-01 00:31:39.048371 | controller | Collecting pluggy<2,>=1.5 2026-03-01 00:31:39.057923 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-03-01 00:31:39.142619 | controller | Collecting pygments>=2.7.2 2026-03-01 00:31:39.147428 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-03-01 00:31:39.180133 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 43.0 MB/s eta 0:00:00 2026-03-01 00:31:39.321503 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-03-01 00:31:41.742478 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-03-01 00:31:41.765600 | controller | 2026-03-01 00:31:42.031142 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-01 00:31:42.031207 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-01 00:31:42.272576 | controller | ok: Runtime: 0:00:04.361878 2026-03-01 00:31:42.288256 | 2026-03-01 00:31:42.288472 | TASK [Update pip] 2026-03-01 00:31:43.647322 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-03-01 00:31:43.888720 | controller | Collecting pip 2026-03-01 00:31:43.967270 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-03-01 00:31:44.045628 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 24.1 MB/s eta 0:00:00 2026-03-01 00:31:44.175260 | controller | Installing collected packages: pip 2026-03-01 00:31:44.175576 | controller | Attempting uninstall: pip 2026-03-01 00:31:44.179075 | controller | Found existing installation: pip 22.2.2 2026-03-01 00:31:44.401710 | controller | Uninstalling pip-22.2.2: 2026-03-01 00:31:44.425929 | controller | Successfully uninstalled pip-22.2.2 2026-03-01 00:31:46.146437 | controller | Successfully installed pip-26.0.1 2026-03-01 00:31:46.683253 | controller | ok: Runtime: 0:00:03.277726 2026-03-01 00:31:46.691692 | 2026-03-01 00:31:46.691813 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-03-01 00:31:47.584978 | controller | changed 2026-03-01 00:31:47.600339 | 2026-03-01 00:31:47.600477 | TASK [Install ansible into virtualenv] 2026-03-01 00:31:48.822966 | controller | Processing ./src/github.com/ansible/ansible 2026-03-01 00:31:48.828142 | controller | Installing build dependencies: started 2026-03-01 00:31:50.548632 | controller | Installing build dependencies: finished with status 'done' 2026-03-01 00:31:52.051284 | controller | Getting requirements to build wheel: started 2026-03-01 00:31:52.051348 | controller | Getting requirements to build wheel: finished with status 'done' 2026-03-01 00:31:52.052572 | controller | Preparing metadata (pyproject.toml): started 2026-03-01 00:31:52.924300 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-03-01 00:31:52.926579 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-03-01 00:31:52.930265 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-03-01 00:31:53.510912 | controller | ERROR 2026-03-01 00:31:53.511288 | controller | { 2026-03-01 00:31:53.511374 | controller | "delta": "0:00:04.813641", 2026-03-01 00:31:53.511421 | controller | "end": "2026-03-01 00:31:53.084259", 2026-03-01 00:31:53.511459 | controller | "msg": "non-zero return code", 2026-03-01 00:31:53.511517 | controller | "rc": 1, 2026-03-01 00:31:53.511554 | controller | "start": "2026-03-01 00:31:48.270618" 2026-03-01 00:31:53.511588 | controller | } failure 2026-03-01 00:31:53.514411 | 2026-03-01 00:31:53.514514 | PLAY RECAP 2026-03-01 00:31:53.514595 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-03-01 00:31:53.514637 | 2026-03-01 00:31:53.642110 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-01 00:31:53.643126 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-01 00:31:54.173542 | 2026-03-01 00:31:54.173672 | PLAY [all] 2026-03-01 00:31:54.198172 | 2026-03-01 00:31:54.198328 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-03-01 00:31:56.095220 | controller | changed: non-zero return code 2026-03-01 00:31:56.109979 | 2026-03-01 00:31:56.110203 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-03-01 00:31:56.139145 | controller | skipping: Conditional result was False 2026-03-01 00:31:56.154162 | 2026-03-01 00:31:56.154413 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-03-01 00:31:56.202237 | 2026-03-01 00:31:56.202582 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-03-01 00:31:56.245952 | 2026-03-01 00:31:56.246291 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-03-01 00:31:56.274320 | controller | skipping: Conditional result was False 2026-03-01 00:31:56.289855 | 2026-03-01 00:31:56.290032 | LOOP [fetch-subunit-output : Generate subunit file] 2026-03-01 00:31:56.333630 | 2026-03-01 00:31:56.334066 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-03-01 00:31:56.361670 | controller | skipping: Conditional result was False 2026-03-01 00:31:56.370467 | 2026-03-01 00:31:56.370590 | TASK [fetch-subunit-output : Remove the temporary file] 2026-03-01 00:31:56.396051 | controller | skipping: Conditional result was False 2026-03-01 00:31:56.405472 | 2026-03-01 00:31:56.405567 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-03-01 00:31:56.431673 | controller | skipping: Conditional result was False 2026-03-01 00:31:56.475032 | 2026-03-01 00:31:56.475143 | PLAY RECAP 2026-03-01 00:31:56.475204 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-01 00:31:56.475233 | 2026-03-01 00:31:56.604282 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-01 00:31:56.606030 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-03-01 00:31:57.237891 | 2026-03-01 00:31:57.238020 | PLAY [all:!appliance*] 2026-03-01 00:31:57.259295 | 2026-03-01 00:31:57.259377 | TASK [unregister the node] 2026-03-01 00:31:57.612819 | controller | skipping: Conditional result was False 2026-03-01 00:31:57.625157 | 2026-03-01 00:31:57.625319 | TASK [include_role : fetch-output] 2026-03-01 00:31:57.662754 | controller | ok 2026-03-01 00:31:57.701163 | 2026-03-01 00:31:57.701255 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-01 00:31:57.777418 | controller | skipping: Conditional result was False 2026-03-01 00:31:57.790158 | 2026-03-01 00:31:57.790306 | TASK [fetch-output : Set log path for single node] 2026-03-01 00:31:57.849024 | controller | ok 2026-03-01 00:31:57.861161 | 2026-03-01 00:31:57.861297 | LOOP [fetch-output : Ensure local output dirs] 2026-03-01 00:31:58.322962 | controller -> localhost | ok: "/var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/logs" 2026-03-01 00:31:58.544949 | controller -> localhost | changed: "/var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/artifacts" 2026-03-01 00:31:58.769104 | controller -> localhost | changed: "/var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/work/docs" 2026-03-01 00:31:58.785339 | 2026-03-01 00:31:58.785463 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-01 00:32:01.072881 | controller | changed: 2026-03-01 00:32:01.073135 | controller | .d..t...... ./ 2026-03-01 00:32:01.073173 | controller | cd+++++++++ controller/ 2026-03-01 00:32:01.073215 | controller | changed: All items complete 2026-03-01 00:32:01.073240 | 2026-03-01 00:32:03.190397 | controller | changed: .d..t...... ./ 2026-03-01 00:32:05.269955 | controller | changed: .d..t...... ./ 2026-03-01 00:32:05.285849 | 2026-03-01 00:32:05.285998 | TASK [include_role : fetch-output-openshift] 2026-03-01 00:32:05.312047 | controller | skipping: Conditional result was False 2026-03-01 00:32:05.320463 | 2026-03-01 00:32:05.320549 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-01 00:32:05.370569 | controller | skipping: Conditional result was False 2026-03-01 00:32:05.382523 | controller | skipping: Conditional result was False 2026-03-01 00:32:05.439463 | 2026-03-01 00:32:05.439637 | PLAY [localhost] 2026-03-01 00:32:05.458052 | 2026-03-01 00:32:05.458284 | TASK [Run Zuul manifest role] 2026-03-01 00:32:05.480662 | localhost | ok 2026-03-01 00:32:05.498428 | 2026-03-01 00:32:05.498520 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-01 00:32:05.976209 | localhost | changed 2026-03-01 00:32:05.980991 | 2026-03-01 00:32:05.981060 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-01 00:32:06.038804 | localhost | ok 2026-03-01 00:32:06.051147 | 2026-03-01 00:32:06.051233 | TASK [Set zuul-log-path fact] 2026-03-01 00:32:06.108282 | localhost | ok 2026-03-01 00:32:06.121033 | 2026-03-01 00:32:06.121103 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-01 00:32:06.162392 | localhost | ok 2026-03-01 00:32:06.173124 | 2026-03-01 00:32:06.173215 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-03-01 00:32:06.228060 | localhost | ok: 2026-03-01 00:32:06.228527 | localhost | { 2026-03-01 00:32:06.228590 | localhost | "auth": { 2026-03-01 00:32:06.228647 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-03-01 00:32:06.228690 | localhost | "username": "9LF91O0RK7JU" 2026-03-01 00:32:06.229025 | localhost | }, 2026-03-01 00:32:06.229092 | localhost | "profile": "rackspace", 2026-03-01 00:32:06.229133 | localhost | "region_name": "ORD" 2026-03-01 00:32:06.229172 | localhost | } 2026-03-01 00:32:06.229236 | 2026-03-01 00:32:06.252087 | 2026-03-01 00:32:06.252386 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-03-01 00:32:06.282047 | localhost | Output suppressed because no_log was given 2026-03-01 00:32:06.310557 | 2026-03-01 00:32:06.310749 | TASK [upload-logs-failover : Initialize control vars] 2026-03-01 00:32:06.342105 | localhost | ok 2026-03-01 00:32:06.348353 | 2026-03-01 00:32:06.348441 | LOOP [upload-logs-failover : Perform log upload] 2026-03-01 00:32:06.383971 | localhost | Output suppressed because no_log was given 2026-03-01 00:32:06.393956 | localhost | included: /var/lib/zuul/builds/22042c7962b746cbaf8d48151dad5875/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-03-01 00:32:06.405535 | 2026-03-01 00:32:06.405628 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-03-01 00:32:06.507876 | localhost | Output suppressed because no_log was given 2026-03-01 00:32:06.525666 | 2026-03-01 00:32:06.525804 | TASK [Upload logs to swift] 2026-03-01 00:32:06.549078 | localhost | ok 2026-03-01 00:32:06.586422 | 2026-03-01 00:32:06.586591 | TASK [Set zuul-log-path fact] 2026-03-01 00:32:06.633131 | localhost | skipping: Conditional result was False 2026-03-01 00:32:06.639913 | 2026-03-01 00:32:06.640056 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-03-01 00:32:07.051088 | localhost -> localhost | ok: Runtime: 0:00:00.008592 2026-03-01 00:32:07.056834 | 2026-03-01 00:32:07.056914 | TASK [upload-logs-swift : Upload logs to swift]