2026-01-03 00:06:42.421735 | Job console starting... 2026-01-03 00:06:42.453652 | Updating repositories 2026-01-03 00:06:42.998444 | Preparing job workspace 2026-01-03 00:06:51.771901 | Running Ansible setup... 2026-01-03 00:06:56.329004 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-03 00:06:56.989262 | 2026-01-03 00:06:56.989390 | PLAY [localhost] 2026-01-03 00:06:56.998355 | 2026-01-03 00:06:56.998438 | TASK [Gathering Facts] 2026-01-03 00:06:58.040007 | localhost | ok 2026-01-03 00:06:58.069111 | 2026-01-03 00:06:58.069265 | TASK [Setup log path fact] 2026-01-03 00:06:58.092341 | localhost | ok 2026-01-03 00:06:58.110150 | 2026-01-03 00:06:58.110240 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-03 00:06:58.140828 | localhost | ok 2026-01-03 00:06:58.152872 | 2026-01-03 00:06:58.153762 | TASK [emit-job-header : Print job information] 2026-01-03 00:06:58.204053 | # Job Information 2026-01-03 00:06:58.204229 | Ansible Version: 2.15.12 2026-01-03 00:06:58.204274 | Job: ansible-test-sanity-docker-devel 2026-01-03 00:06:58.204400 | Pipeline: periodic 2026-01-03 00:06:58.204429 | Executor: ze02.softwarefactory-project.io 2026-01-03 00:06:58.204455 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-03 00:06:58.204485 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a5a/ansible/a5a89ea34c0a4ec2b7b13d9ba35166aa/ 2026-01-03 00:06:58.204513 | Event ID: 84f60a54a6bb4d9ab16f9cfd1e63d8f4 2026-01-03 00:06:58.209766 | 2026-01-03 00:06:58.209854 | LOOP [emit-job-header : Print node information] 2026-01-03 00:06:58.323337 | localhost | ok: 2026-01-03 00:06:58.323722 | localhost | # Node Information 2026-01-03 00:06:58.323792 | localhost | Inventory Hostname: controller 2026-01-03 00:06:58.323838 | localhost | Hostname: np0005573527 2026-01-03 00:06:58.323881 | localhost | Username: zuul 2026-01-03 00:06:58.323935 | localhost | Distro: Fedora 37 2026-01-03 00:06:58.323978 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-03 00:06:58.324024 | localhost | Region: ca-ymq-1 2026-01-03 00:06:58.324077 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-03 00:06:58.324130 | localhost | Product Name: OpenStack Nova 2026-01-03 00:06:58.324179 | localhost | Interface IP: 162.253.55.43 2026-01-03 00:06:58.344874 | 2026-01-03 00:06:58.345096 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-03 00:06:58.766965 | localhost -> localhost | changed 2026-01-03 00:06:58.773353 | 2026-01-03 00:06:58.773419 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-03 00:06:59.757989 | localhost -> localhost | changed 2026-01-03 00:06:59.784029 | 2026-01-03 00:06:59.784109 | PLAY [all:!appliance*] 2026-01-03 00:06:59.806191 | 2026-01-03 00:06:59.806317 | TASK [include_role : start-zuul-console] 2026-01-03 00:06:59.828625 | controller | ok 2026-01-03 00:06:59.847974 | 2026-01-03 00:06:59.848067 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-03 00:07:00.262228 | controller | ok 2026-01-03 00:07:00.316089 | 2026-01-03 00:07:00.316288 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-03 00:07:23.629980 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-03 00:07:23.641686 | 2026-01-03 00:07:23.641820 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-03 00:07:24.172490 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.187064 | 2026-01-03 00:07:24.187230 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-03 00:07:24.214038 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.227890 | 2026-01-03 00:07:24.228161 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-03 00:07:24.257001 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.272024 | 2026-01-03 00:07:24.272234 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-03 00:07:24.300077 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.314593 | 2026-01-03 00:07:24.314835 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-03 00:07:24.352468 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.367895 | 2026-01-03 00:07:24.368084 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-03 00:07:24.395544 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.418926 | 2026-01-03 00:07:24.419025 | TASK [Disable Fedora Modular] 2026-01-03 00:07:24.756517 | controller | changed 2026-01-03 00:07:24.762254 | 2026-01-03 00:07:24.762320 | TASK [Enable EPEL] 2026-01-03 00:07:24.786828 | controller | skipping: Conditional result was False 2026-01-03 00:07:24.797363 | 2026-01-03 00:07:24.797489 | TASK [Register the RHEL node] 2026-01-03 00:07:25.360713 | 2026-01-03 00:07:25.360999 | TASK [Show the subscription-manager status] 2026-01-03 00:07:25.923755 | controller | skipping: Conditional result was False 2026-01-03 00:07:25.931053 | 2026-01-03 00:07:25.931157 | TASK [Enable EPEL on RHEL] 2026-01-03 00:07:26.474278 | controller | skipping: Conditional result was False 2026-01-03 00:07:26.489048 | 2026-01-03 00:07:26.489205 | TASK [Install git and tox] 2026-01-03 00:08:44.792705 | controller | changed 2026-01-03 00:08:44.799794 | 2026-01-03 00:08:44.799876 | TASK [include_role : prepare-workspace] 2026-01-03 00:08:44.830643 | controller | ok 2026-01-03 00:08:44.851941 | 2026-01-03 00:08:44.852071 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-03 00:08:45.100339 | controller | ok 2026-01-03 00:08:45.117812 | 2026-01-03 00:08:45.117995 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-03 00:08:57.227218 | controller | Output suppressed because no_log was given 2026-01-03 00:08:57.240603 | 2026-01-03 00:08:57.240724 | TASK [include_role : prepare-workspace-openshift] 2026-01-03 00:08:57.266629 | controller | skipping: Conditional result was False 2026-01-03 00:08:57.294035 | 2026-01-03 00:08:57.294202 | PLAY [all:!appliance] 2026-01-03 00:08:57.311446 | 2026-01-03 00:08:57.311523 | TASK [Run add-build-sshkey role (RSA)] 2026-01-03 00:08:57.343528 | controller | ok 2026-01-03 00:08:57.360369 | 2026-01-03 00:08:57.360500 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-03 00:08:57.612402 | controller -> localhost | ok 2026-01-03 00:08:57.620429 | 2026-01-03 00:08:57.620498 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-03 00:08:57.653693 | controller | ok 2026-01-03 00:08:57.670232 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-03 00:08:57.676182 | 2026-01-03 00:08:57.676245 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-03 00:08:58.326555 | controller -> localhost | Generating public/private rsa key pair. 2026-01-03 00:08:58.326964 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_rsa. 2026-01-03 00:08:58.327010 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_rsa.pub. 2026-01-03 00:08:58.327039 | controller -> localhost | The key fingerprint is: 2026-01-03 00:08:58.327066 | controller -> localhost | SHA256:dBLKkLr5yRKg2DiTI8KhITyTkLcUVbNBUT+uqcGqE34 zuul-build-sshkey 2026-01-03 00:08:58.327092 | controller -> localhost | The key's randomart image is: 2026-01-03 00:08:58.327119 | controller -> localhost | +---[RSA 2048]----+ 2026-01-03 00:08:58.327143 | controller -> localhost | | ..oo+*oo | 2026-01-03 00:08:58.327169 | controller -> localhost | |o o .o = o | 2026-01-03 00:08:58.327194 | controller -> localhost | |oo.o + o + | 2026-01-03 00:08:58.327217 | controller -> localhost | |+*o . + . | 2026-01-03 00:08:58.327241 | controller -> localhost | |**+o S . | 2026-01-03 00:08:58.327281 | controller -> localhost | |%.* . o | 2026-01-03 00:08:58.327312 | controller -> localhost | |o= = .o o | 2026-01-03 00:08:58.327339 | controller -> localhost | | + E. o | 2026-01-03 00:08:58.327364 | controller -> localhost | | .=. . | 2026-01-03 00:08:58.327393 | controller -> localhost | +----[SHA256]-----+ 2026-01-03 00:08:58.327467 | controller -> localhost | ok: Runtime: 0:00:00.194246 2026-01-03 00:08:58.337623 | 2026-01-03 00:08:58.337738 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-03 00:08:58.373588 | controller | ok 2026-01-03 00:08:58.389899 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-03 00:08:58.403998 | 2026-01-03 00:08:58.404084 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-03 00:08:58.434990 | controller | skipping: Conditional result was False 2026-01-03 00:08:58.445441 | 2026-01-03 00:08:58.445616 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-03 00:08:58.869227 | controller | changed 2026-01-03 00:08:58.879117 | 2026-01-03 00:08:58.879214 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-03 00:08:59.109097 | controller | ok 2026-01-03 00:08:59.188247 | 2026-01-03 00:08:59.188448 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-03 00:08:59.870803 | controller | changed 2026-01-03 00:08:59.886906 | 2026-01-03 00:08:59.887113 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-03 00:09:00.558360 | controller | changed 2026-01-03 00:09:00.573541 | 2026-01-03 00:09:00.573857 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-03 00:09:00.603197 | controller | skipping: Conditional result was False 2026-01-03 00:09:00.618787 | 2026-01-03 00:09:00.619043 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-03 00:09:01.015049 | controller -> localhost | changed 2026-01-03 00:09:01.026490 | 2026-01-03 00:09:01.026560 | TASK [add-build-sshkey : Add back temp key] 2026-01-03 00:09:01.316260 | controller -> localhost | Identity added: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_rsa (zuul-build-sshkey) 2026-01-03 00:09:01.316648 | controller -> localhost | ok: Runtime: 0:00:00.013662 2026-01-03 00:09:01.329934 | 2026-01-03 00:09:01.330062 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-03 00:09:01.660784 | controller | ok 2026-01-03 00:09:01.674246 | 2026-01-03 00:09:01.674389 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-03 00:09:01.712464 | controller | skipping: Conditional result was False 2026-01-03 00:09:01.728448 | 2026-01-03 00:09:01.728605 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-03 00:09:01.763034 | controller | ok 2026-01-03 00:09:01.786705 | 2026-01-03 00:09:01.786857 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-03 00:09:02.091443 | controller -> localhost | ok 2026-01-03 00:09:02.101142 | 2026-01-03 00:09:02.101321 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-03 00:09:02.144981 | controller | ok 2026-01-03 00:09:02.158782 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-03 00:09:02.170501 | 2026-01-03 00:09:02.170774 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-03 00:09:02.477779 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-03 00:09:02.478115 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_ecdsa. 2026-01-03 00:09:02.478175 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_ecdsa.pub. 2026-01-03 00:09:02.478233 | controller -> localhost | The key fingerprint is: 2026-01-03 00:09:02.478279 | controller -> localhost | SHA256:OKH2I5MhNX7KcXCUsULK4n/jRnaWEJa792D1YCeaoCQ zuul-build-sshkey 2026-01-03 00:09:02.478328 | controller -> localhost | The key's randomart image is: 2026-01-03 00:09:02.478369 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-03 00:09:02.478408 | controller -> localhost | | . +o | 2026-01-03 00:09:02.478447 | controller -> localhost | | . o =.. | 2026-01-03 00:09:02.478490 | controller -> localhost | |. o * * | 2026-01-03 00:09:02.478552 | controller -> localhost | |.E + X o = . | 2026-01-03 00:09:02.478614 | controller -> localhost | | .+ B O S = | 2026-01-03 00:09:02.478709 | controller -> localhost | | .= % @ . | 2026-01-03 00:09:02.478774 | controller -> localhost | | .OoB o | 2026-01-03 00:09:02.478817 | controller -> localhost | | o+.. . | 2026-01-03 00:09:02.478858 | controller -> localhost | | .. | 2026-01-03 00:09:02.478897 | controller -> localhost | +----[SHA256]-----+ 2026-01-03 00:09:02.478991 | controller -> localhost | ok: Runtime: 0:00:00.015423 2026-01-03 00:09:02.493557 | 2026-01-03 00:09:02.493728 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-03 00:09:02.532920 | controller | ok 2026-01-03 00:09:02.549501 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-03 00:09:02.563586 | 2026-01-03 00:09:02.563697 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-03 00:09:02.589653 | controller | skipping: Conditional result was False 2026-01-03 00:09:02.599731 | 2026-01-03 00:09:02.599826 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-03 00:09:02.903539 | controller | changed 2026-01-03 00:09:02.912451 | 2026-01-03 00:09:02.912565 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-03 00:09:03.137625 | controller | ok 2026-01-03 00:09:03.150790 | 2026-01-03 00:09:03.150983 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-03 00:09:03.830382 | controller | changed 2026-01-03 00:09:03.843474 | 2026-01-03 00:09:03.843649 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-03 00:09:04.521478 | controller | changed 2026-01-03 00:09:04.536120 | 2026-01-03 00:09:04.536287 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-03 00:09:04.588211 | controller | skipping: Conditional result was False 2026-01-03 00:09:04.608623 | 2026-01-03 00:09:04.608911 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-03 00:09:04.951367 | controller -> localhost | changed 2026-01-03 00:09:04.963858 | 2026-01-03 00:09:04.963966 | TASK [add-build-sshkey : Add back temp key] 2026-01-03 00:09:05.304542 | controller -> localhost | Identity added: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/a5a89ea34c0a4ec2b7b13d9ba35166aa_id_ecdsa (zuul-build-sshkey) 2026-01-03 00:09:05.304747 | controller -> localhost | ok: Runtime: 0:00:00.007445 2026-01-03 00:09:05.311187 | 2026-01-03 00:09:05.311254 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-03 00:09:05.515139 | controller | ok 2026-01-03 00:09:05.523835 | 2026-01-03 00:09:05.524019 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-03 00:09:05.549483 | controller | skipping: Conditional result was False 2026-01-03 00:09:05.568606 | 2026-01-03 00:09:05.568803 | TASK [include_role : remove-zuul-sshkey] 2026-01-03 00:09:05.583777 | controller | skipping: Conditional result was False 2026-01-03 00:09:05.591395 | 2026-01-03 00:09:05.591508 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-03 00:09:05.798381 | controller | ok: "logs" 2026-01-03 00:09:05.798623 | controller | ok: All items complete 2026-01-03 00:09:05.798653 | 2026-01-03 00:09:05.998081 | controller | ok: "artifacts" 2026-01-03 00:09:06.197658 | controller | ok: "docs" 2026-01-03 00:09:06.222076 | 2026-01-03 00:09:06.222291 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-03 00:09:06.503109 | controller | changed: "logs" 2026-01-03 00:09:06.741313 | controller | changed: "artifacts" 2026-01-03 00:09:06.908510 | controller | changed: "docs" 2026-01-03 00:09:06.977531 | 2026-01-03 00:09:06.977740 | PLAY RECAP 2026-01-03 00:09:06.977820 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-03 00:09:06.977869 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-03 00:09:06.977896 | 2026-01-03 00:09:07.140970 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-03 00:09:07.142107 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-03 00:09:07.713194 | 2026-01-03 00:09:07.713316 | PLAY [all] 2026-01-03 00:09:07.736047 | 2026-01-03 00:09:07.736184 | TASK [Install binary dependencies] 2026-01-03 00:09:07.786523 | controller | ok 2026-01-03 00:09:07.806023 | 2026-01-03 00:09:07.806103 | TASK [bindep : Include find tasks] 2026-01-03 00:09:07.835658 | controller | ok 2026-01-03 00:09:07.843200 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-03 00:09:07.849345 | 2026-01-03 00:09:07.849408 | TASK [bindep : Look for bindep.txt] 2026-01-03 00:09:08.274469 | controller | ok 2026-01-03 00:09:08.294042 | 2026-01-03 00:09:08.294148 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:09:08.308961 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.317514 | 2026-01-03 00:09:08.317606 | TASK [bindep : Look for other-requirements.txt] 2026-01-03 00:09:08.530206 | controller | ok 2026-01-03 00:09:08.542865 | 2026-01-03 00:09:08.543013 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:09:08.570107 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.584611 | 2026-01-03 00:09:08.584876 | TASK [bindep : Look for bindep fallback file] 2026-01-03 00:09:08.622400 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.638100 | 2026-01-03 00:09:08.638256 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:09:08.665752 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.679764 | 2026-01-03 00:09:08.679912 | TASK [bindep : Include bindep tasks] 2026-01-03 00:09:08.706351 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.719920 | 2026-01-03 00:09:08.720071 | TASK [bindep : Include install tasks] 2026-01-03 00:09:08.746980 | controller | skipping: Conditional result was False 2026-01-03 00:09:08.760513 | 2026-01-03 00:09:08.760658 | LOOP [bindep : Include package tasks] 2026-01-03 00:09:08.843361 | 2026-01-03 00:09:08.843660 | TASK [Run test-setup role] 2026-01-03 00:09:08.875462 | controller | ok 2026-01-03 00:09:08.910020 | 2026-01-03 00:09:08.910186 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-03 00:09:09.122850 | controller | ok 2026-01-03 00:09:09.132040 | 2026-01-03 00:09:09.132139 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-03 00:09:09.677845 | controller | skipping: Conditional result was False 2026-01-03 00:09:09.734360 | 2026-01-03 00:09:09.734594 | PLAY RECAP 2026-01-03 00:09:09.734667 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-03 00:09:09.734720 | 2026-01-03 00:09:09.855319 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-03 00:09:09.856466 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-03 00:09:10.514555 | 2026-01-03 00:09:10.514712 | PLAY [controller] 2026-01-03 00:09:10.534461 | 2026-01-03 00:09:10.534569 | TASK [Create the /root directory] 2026-01-03 00:09:10.918837 | controller | ok 2026-01-03 00:09:10.924561 | 2026-01-03 00:09:10.924633 | TASK [Install glibc-langpack-en] 2026-01-03 00:09:14.844237 | controller | ok: Nothing to do 2026-01-03 00:09:14.850169 | 2026-01-03 00:09:14.850243 | TASK [Ensure controller directory exists] 2026-01-03 00:09:15.073368 | controller | changed 2026-01-03 00:09:15.079737 | 2026-01-03 00:09:15.079839 | TASK [Install container runtime] 2026-01-03 00:09:15.151988 | controller | ok 2026-01-03 00:09:15.187876 | 2026-01-03 00:09:15.188010 | LOOP [ensure-podman : Find distribution installation] 2026-01-03 00:09:15.226521 | controller | ok: "/var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-03 00:09:15.244771 | controller | included: /var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-03 00:09:15.254537 | 2026-01-03 00:09:15.254644 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-03 00:10:19.833846 | controller | changed 2026-01-03 00:10:19.840231 | 2026-01-03 00:10:19.840299 | TASK [ensure-podman : Fetch podman version] 2026-01-03 00:10:20.409565 | controller | Client: Podman Engine 2026-01-03 00:10:20.433526 | controller | Version: 4.6.2 2026-01-03 00:10:20.433558 | controller | API Version: 4.6.2 2026-01-03 00:10:20.433566 | controller | Go Version: go1.19.12 2026-01-03 00:10:20.433584 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-03 00:10:20.433592 | controller | OS/Arch: linux/amd64 2026-01-03 00:10:20.876383 | controller | ok: Runtime: 0:00:00.219347 2026-01-03 00:10:20.890246 | 2026-01-03 00:10:20.890412 | TASK [ensure-podman : Print podman version installed] 2026-01-03 00:10:20.931106 | Podman version: Client: Podman Engine 2026-01-03 00:10:20.931292 | Version: 4.6.2 2026-01-03 00:10:20.931320 | API Version: 4.6.2 2026-01-03 00:10:20.931341 | Go Version: go1.19.12 2026-01-03 00:10:20.931359 | Built: Mon Aug 28 19:38:31 2023 2026-01-03 00:10:20.931377 | OS/Arch: linux/amd64 2026-01-03 00:10:20.937416 | 2026-01-03 00:10:20.937500 | TASK [ensure-podman : Validate podman engine] 2026-01-03 00:10:21.471199 | controller | skipping: Conditional result was False 2026-01-03 00:10:21.480902 | 2026-01-03 00:10:21.481041 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-03 00:10:21.496137 | controller | skipping: Conditional result was False 2026-01-03 00:10:21.515578 | 2026-01-03 00:10:21.515770 | TASK [Ensure python3.8 is present] 2026-01-03 00:10:21.550473 | controller | skipping: Conditional result was False 2026-01-03 00:10:21.559101 | 2026-01-03 00:10:21.559192 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-03 00:10:21.581446 | controller | ok 2026-01-03 00:10:21.606091 | 2026-01-03 00:10:21.606160 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-03 00:10:23.065533 | controller | ok: Nothing to do 2026-01-03 00:10:23.071712 | 2026-01-03 00:10:23.071790 | TASK [our-ensure-python : Also install python3-devel] 2026-01-03 00:10:31.791450 | controller | changed 2026-01-03 00:10:31.802889 | 2026-01-03 00:10:31.802959 | TASK [Run ensure-virtualenv role] 2026-01-03 00:10:31.825153 | controller | ok 2026-01-03 00:10:31.859609 | 2026-01-03 00:10:31.859803 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-03 00:10:32.138523 | controller | /usr/bin/virtualenv 2026-01-03 00:10:32.449376 | controller | ok: Runtime: 0:00:00.003442 2026-01-03 00:10:32.465323 | 2026-01-03 00:10:32.465496 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-03 00:10:32.502164 | controller | skipping: Conditional result was False 2026-01-03 00:10:32.502535 | controller | ok: All items complete 2026-01-03 00:10:32.502574 | 2026-01-03 00:10:32.537248 | 2026-01-03 00:10:32.537563 | TASK [Find the full path of the Python interpreter] 2026-01-03 00:10:32.779444 | controller | /usr/bin/python3 2026-01-03 00:10:33.086893 | controller | ok 2026-01-03 00:10:33.096263 | 2026-01-03 00:10:33.097344 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-03 00:10:33.884598 | controller | created virtual environment CPython3.11.0.final.0-64 in 463ms 2026-01-03 00:10:33.904301 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-03 00:10:33.904343 | 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-01-03 00:10:33.904353 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-03 00:10:33.904369 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-03 00:10:34.143438 | controller | changed 2026-01-03 00:10:34.154259 | 2026-01-03 00:10:34.154364 | TASK [Set selinux package] 2026-01-03 00:10:34.196042 | controller | ok 2026-01-03 00:10:34.208562 | 2026-01-03 00:10:34.208727 | TASK [Set selinux package (Fedora)] 2026-01-03 00:10:34.253185 | controller | ok 2026-01-03 00:10:34.258728 | 2026-01-03 00:10:34.258791 | TASK [Install selinux into virtualenv] 2026-01-03 00:10:59.790472 | controller | Collecting selinux-please-lie-to-me 2026-01-03 00:11:24.027146 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-03 00:11:24.372352 | controller | Collecting setuptools<50.0.0 2026-01-03 00:11:24.379235 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-03 00:11:24.431205 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 17.7 MB/s eta 0:00:00 2026-01-03 00:11:24.513352 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-03 00:11:24.513572 | controller | Attempting uninstall: setuptools 2026-01-03 00:11:24.516030 | controller | Found existing installation: setuptools 62.6.0 2026-01-03 00:11:24.579773 | controller | Uninstalling setuptools-62.6.0: 2026-01-03 00:11:24.589332 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-03 00:11:24.969163 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-03 00:11:36.378800 | controller | 2026-01-03 00:11:36.465356 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-03 00:11:36.465399 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-03 00:11:36.833738 | controller | ok: Runtime: 0:01:01.978366 2026-01-03 00:11:36.839833 | 2026-01-03 00:11:36.839898 | TASK [Install pytest-forked into virtualenv] 2026-01-03 00:12:00.561643 | controller | Collecting pytest-forked 2026-01-03 00:12:12.899739 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-03 00:12:12.940680 | controller | Collecting py 2026-01-03 00:12:12.945020 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-03 00:12:12.966655 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.2 MB/s eta 0:00:00 2026-01-03 00:12:13.078099 | controller | Collecting pytest>=3.10 2026-01-03 00:12:13.086546 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-03 00:12:13.104365 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 25.2 MB/s eta 0:00:00 2026-01-03 00:12:13.140181 | controller | Collecting iniconfig>=1.0.1 2026-01-03 00:12:13.144921 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-03 00:12:13.187811 | controller | Collecting packaging>=22 2026-01-03 00:12:13.191884 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-03 00:12:13.199968 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 17.5 MB/s eta 0:00:00 2026-01-03 00:12:13.234231 | controller | Collecting pluggy<2,>=1.5 2026-01-03 00:12:13.237309 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-03 00:12:13.281655 | controller | Collecting pygments>=2.7.2 2026-01-03 00:12:13.288975 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-03 00:12:13.314342 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 54.4 MB/s eta 0:00:00 2026-01-03 00:12:13.384824 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-03 00:12:14.424223 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-01-03 00:12:14.432807 | controller | 2026-01-03 00:12:14.500858 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-03 00:12:14.500910 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-03 00:12:14.567547 | controller | ok: Runtime: 0:00:37.461437 2026-01-03 00:12:14.581872 | 2026-01-03 00:12:14.582225 | TASK [Update pip] 2026-01-03 00:12:15.108153 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-03 00:12:25.283215 | controller | Collecting pip 2026-01-03 00:12:37.475821 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-03 00:12:37.529635 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.5 MB/s eta 0:00:00 2026-01-03 00:12:37.593575 | controller | Installing collected packages: pip 2026-01-03 00:12:37.593691 | controller | Attempting uninstall: pip 2026-01-03 00:12:37.595850 | controller | Found existing installation: pip 22.2.2 2026-01-03 00:12:37.730619 | controller | Uninstalling pip-22.2.2: 2026-01-03 00:12:37.745158 | controller | Successfully uninstalled pip-22.2.2 2026-01-03 00:12:38.587344 | controller | Successfully installed pip-25.3 2026-01-03 00:12:39.152808 | controller | ok: Runtime: 0:00:23.844662 2026-01-03 00:12:39.169256 | 2026-01-03 00:12:39.169561 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-03 00:12:39.405937 | controller | changed 2026-01-03 00:12:39.419394 | 2026-01-03 00:12:39.419543 | TASK [Install ansible into virtualenv] 2026-01-03 00:12:39.929595 | controller | Processing ./src/github.com/ansible/ansible 2026-01-03 00:12:39.932967 | controller | Installing build dependencies: started 2026-01-03 00:13:00.562940 | controller | Installing build dependencies: finished with status 'done' 2026-01-03 00:13:00.564245 | controller | Getting requirements to build wheel: started 2026-01-03 00:13:01.280918 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-03 00:13:01.281546 | controller | Preparing metadata (pyproject.toml): started 2026-01-03 00:13:01.734624 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-03 00:13:01.741763 | 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-01-03 00:13:01.746224 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-03 00:13:01.985113 | controller | ERROR 2026-01-03 00:13:01.985380 | controller | { 2026-01-03 00:13:01.985451 | controller | "delta": "0:00:22.156168", 2026-01-03 00:13:01.985496 | controller | "end": "2026-01-03 00:13:01.808946", 2026-01-03 00:13:01.985535 | controller | "msg": "non-zero return code", 2026-01-03 00:13:01.985588 | controller | "rc": 1, 2026-01-03 00:13:01.985625 | controller | "start": "2026-01-03 00:12:39.652778" 2026-01-03 00:13:01.985673 | controller | } failure 2026-01-03 00:13:01.988640 | 2026-01-03 00:13:01.988797 | PLAY RECAP 2026-01-03 00:13:01.988894 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-03 00:13:01.988949 | 2026-01-03 00:13:02.120548 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-03 00:13:02.122103 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-03 00:13:02.757052 | 2026-01-03 00:13:02.757175 | PLAY [all] 2026-01-03 00:13:02.780144 | 2026-01-03 00:13:02.780231 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-03 00:13:03.059347 | controller | changed: non-zero return code 2026-01-03 00:13:03.067158 | 2026-01-03 00:13:03.067260 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-03 00:13:03.091900 | controller | skipping: Conditional result was False 2026-01-03 00:13:03.100107 | 2026-01-03 00:13:03.100214 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-03 00:13:03.133718 | 2026-01-03 00:13:03.133918 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-03 00:13:03.167492 | 2026-01-03 00:13:03.167724 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-03 00:13:03.192517 | controller | skipping: Conditional result was False 2026-01-03 00:13:03.203194 | 2026-01-03 00:13:03.203323 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-03 00:13:03.237057 | 2026-01-03 00:13:03.237279 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-03 00:13:03.262471 | controller | skipping: Conditional result was False 2026-01-03 00:13:03.272102 | 2026-01-03 00:13:03.272216 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-03 00:13:03.297576 | controller | skipping: Conditional result was False 2026-01-03 00:13:03.307820 | 2026-01-03 00:13:03.307932 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-03 00:13:03.323260 | controller | skipping: Conditional result was False 2026-01-03 00:13:03.363075 | 2026-01-03 00:13:03.363222 | PLAY RECAP 2026-01-03 00:13:03.363279 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-03 00:13:03.363306 | 2026-01-03 00:13:03.460188 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-03 00:13:03.462246 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-03 00:13:04.032028 | 2026-01-03 00:13:04.032159 | PLAY [all:!appliance*] 2026-01-03 00:13:04.054268 | 2026-01-03 00:13:04.054441 | TASK [unregister the node] 2026-01-03 00:13:04.589443 | controller | skipping: Conditional result was False 2026-01-03 00:13:04.603776 | 2026-01-03 00:13:04.603952 | TASK [include_role : fetch-output] 2026-01-03 00:13:04.661194 | controller | ok 2026-01-03 00:13:04.707270 | 2026-01-03 00:13:04.707457 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-03 00:13:04.765196 | controller | skipping: Conditional result was False 2026-01-03 00:13:04.779405 | 2026-01-03 00:13:04.779565 | TASK [fetch-output : Set log path for single node] 2026-01-03 00:13:04.818268 | controller | ok 2026-01-03 00:13:04.826890 | 2026-01-03 00:13:04.826988 | LOOP [fetch-output : Ensure local output dirs] 2026-01-03 00:13:05.206109 | controller -> localhost | ok: "/var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/logs" 2026-01-03 00:13:05.506214 | controller -> localhost | changed: "/var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/artifacts" 2026-01-03 00:13:05.731953 | controller -> localhost | changed: "/var/lib/zuul/builds/a5a89ea34c0a4ec2b7b13d9ba35166aa/work/docs" 2026-01-03 00:13:05.748129 | 2026-01-03 00:13:05.748224 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-03 00:13:06.376600 | controller | changed: 2026-01-03 00:13:06.377055 | controller | .d..t...... ./ 2026-01-03 00:13:06.377100 | controller | cd+++++++++ controller/ 2026-01-03 00:13:06.377145 | controller | changed: All items complete 2026-01-03 00:13:06.377178 | 2026-01-03 00:13:06.807314 | controller | changed: .d..t...... ./ 2026-01-03 00:13:07.304531 | controller | changed: .d..t...... ./ 2026-01-03 00:13:07.330754 | 2026-01-03 00:13:07.330926 | TASK [include_role : fetch-output-openshift] 2026-01-03 00:13:07.357057 | controller | skipping: Conditional result was False 2026-01-03 00:13:07.363771 | 2026-01-03 00:13:07.363845 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-03 00:13:07.398432 | controller | skipping: Conditional result was False 2026-01-03 00:13:07.413827 | controller | skipping: Conditional result was False 2026-01-03 00:13:07.448343 | 2026-01-03 00:13:07.448462 | PLAY [localhost] 2026-01-03 00:13:07.460770 | 2026-01-03 00:13:07.460833 | TASK [Run Zuul manifest role] 2026-01-03 00:13:07.480528 | localhost | ok 2026-01-03 00:13:07.497561 | 2026-01-03 00:13:07.497728 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-03 00:13:07.917644 | localhost | changed 2026-01-03 00:13:07.926592 | 2026-01-03 00:13:07.926735 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-03 00:13:07.955060 | localhost | ok 2026-01-03 00:13:07.962998 | 2026-01-03 00:13:07.963060 | TASK [Set zuul-log-path fact] 2026-01-03 00:13:07.981565 | localhost | ok 2026-01-03 00:13:07.995323 | 2026-01-03 00:13:07.995388 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-03 00:13:08.023752 | localhost | ok 2026-01-03 00:13:08.031602 | 2026-01-03 00:13:08.031659 | LOOP [Run upload-logs-swift role] 2026-01-03 00:13:08.066351 | localhost | Output suppressed because no_log was given 2026-01-03 00:13:08.091450 | 2026-01-03 00:13:08.091549 | TASK [Set zuul-log-path fact] 2026-01-03 00:13:08.125905 | localhost | skipping: Conditional result was False 2026-01-03 00:13:08.130781 | 2026-01-03 00:13:08.130846 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-03 00:13:08.562998 | localhost -> localhost | ok: Runtime: 0:00:00.008081 2026-01-03 00:13:08.602375 | 2026-01-03 00:13:08.602513 | TASK [upload-logs-swift : Upload logs to swift]