2025-10-01 00:11:46.745979 | Job console starting...
2025-10-01 00:11:46.756886 | Updating repositories
2025-10-01 00:11:46.937126 | Preparing job workspace
2025-10-01 00:11:51.243946 | Running Ansible setup...
2025-10-01 00:11:56.401530 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-01 00:11:57.105833 | 
2025-10-01 00:11:57.106058 | PLAY [localhost]
2025-10-01 00:11:57.116226 | 
2025-10-01 00:11:57.116312 | TASK [Gathering Facts]
2025-10-01 00:11:58.162471 | localhost | ok
2025-10-01 00:11:58.195876 | 
2025-10-01 00:11:58.196136 | TASK [Setup log path fact]
2025-10-01 00:11:58.219378 | localhost | ok
2025-10-01 00:11:58.238878 | 
2025-10-01 00:11:58.239009 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 00:11:58.292396 | localhost | ok
2025-10-01 00:11:58.308914 | 
2025-10-01 00:11:58.309182 | TASK [emit-job-header : Print job information]
2025-10-01 00:11:58.350030 | # Job Information
2025-10-01 00:11:58.350306 | Ansible Version: 2.15.12
2025-10-01 00:11:58.350354 | Job: ansible-test-sanity-docker-devel
2025-10-01 00:11:58.350383 | Pipeline: periodic
2025-10-01 00:11:58.350409 | Executor: ze02.softwarefactory-project.io
2025-10-01 00:11:58.350433 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-01 00:11:58.350461 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/e4d/ansible/e4d7cfab423f4f84ad4d2170749cb49b/
2025-10-01 00:11:58.350487 | Event ID: 2d247e7dd365484888695175254b0a86
2025-10-01 00:11:58.358067 | 
2025-10-01 00:11:58.358167 | LOOP [emit-job-header : Print node information]
2025-10-01 00:11:58.483821 | localhost | ok:
2025-10-01 00:11:58.484064 | localhost | # Node Information
2025-10-01 00:11:58.484093 | localhost | Inventory Hostname: controller
2025-10-01 00:11:58.484116 | localhost | Hostname: np0005463708
2025-10-01 00:11:58.484137 | localhost | Username: zuul
2025-10-01 00:11:58.484163 | localhost | Distro: Fedora 37
2025-10-01 00:11:58.484184 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-10-01 00:11:58.484204 | localhost | Region: ca-ymq-1
2025-10-01 00:11:58.484224 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-01 00:11:58.484244 | localhost | Product Name: OpenStack Nova
2025-10-01 00:11:58.484264 | localhost | Interface IP: 162.253.55.209
2025-10-01 00:11:58.496537 | 
2025-10-01 00:11:58.496616 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-01 00:11:59.020762 | localhost -> localhost | changed
2025-10-01 00:11:59.030998 | 
2025-10-01 00:11:59.031162 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-01 00:12:00.082635 | localhost -> localhost | changed
2025-10-01 00:12:00.115239 | 
2025-10-01 00:12:00.115853 | PLAY [all:!appliance*]
2025-10-01 00:12:00.133827 | 
2025-10-01 00:12:00.133978 | TASK [include_role : start-zuul-console]
2025-10-01 00:12:00.156420 | controller | ok
2025-10-01 00:12:00.170248 | 
2025-10-01 00:12:00.170362 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-01 00:12:00.607342 | controller | ok
2025-10-01 00:12:00.629076 | 
2025-10-01 00:12:00.629188 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-01 00:12:07.976448 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-01 00:12:07.993012 | 
2025-10-01 00:12:07.993161 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-01 00:12:08.549617 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.562739 | 
2025-10-01 00:12:08.562899 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-01 00:12:08.601208 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.615215 | 
2025-10-01 00:12:08.615490 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-01 00:12:08.653922 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.663119 | 
2025-10-01 00:12:08.663243 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-01 00:12:08.689397 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.699268 | 
2025-10-01 00:12:08.699378 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-01 00:12:08.725915 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.737486 | 
2025-10-01 00:12:08.737642 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-01 00:12:08.774682 | controller | skipping: Conditional result was False
2025-10-01 00:12:08.825171 | 
2025-10-01 00:12:08.825325 | TASK [Disable Fedora Modular]
2025-10-01 00:12:09.304533 | controller | changed
2025-10-01 00:12:09.322068 | 
2025-10-01 00:12:09.322228 | TASK [Enable EPEL]
2025-10-01 00:12:09.360249 | controller | skipping: Conditional result was False
2025-10-01 00:12:09.369174 | 
2025-10-01 00:12:09.369269 | TASK [Register the RHEL node]
2025-10-01 00:12:09.933887 | 
2025-10-01 00:12:09.934124 | TASK [Show the subscription-manager status]
2025-10-01 00:12:10.477272 | controller | skipping: Conditional result was False
2025-10-01 00:12:10.491784 | 
2025-10-01 00:12:10.491985 | TASK [Enable EPEL on RHEL]
2025-10-01 00:12:11.052703 | controller | skipping: Conditional result was False
2025-10-01 00:12:11.068561 | 
2025-10-01 00:12:11.068868 | TASK [Install git and tox]
2025-10-01 00:13:50.219381 | controller | changed
2025-10-01 00:13:50.246338 | 
2025-10-01 00:13:50.246438 | TASK [include_role : prepare-workspace]
2025-10-01 00:13:50.288601 | controller | ok
2025-10-01 00:13:50.318397 | 
2025-10-01 00:13:50.318532 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-01 00:13:50.582320 | controller | ok
2025-10-01 00:13:50.599474 | 
2025-10-01 00:13:50.599695 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-01 00:14:03.360483 | controller | Output suppressed because no_log was given
2025-10-01 00:14:03.372993 | 
2025-10-01 00:14:03.373060 | TASK [include_role : prepare-workspace-openshift]
2025-10-01 00:14:03.398565 | controller | skipping: Conditional result was False
2025-10-01 00:14:03.423500 | 
2025-10-01 00:14:03.423587 | PLAY [all:!appliance]
2025-10-01 00:14:03.439853 | 
2025-10-01 00:14:03.439925 | TASK [Run add-build-sshkey role (RSA)]
2025-10-01 00:14:03.472077 | controller | ok
2025-10-01 00:14:03.488767 | 
2025-10-01 00:14:03.488849 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-01 00:14:03.797470 | controller -> localhost | ok
2025-10-01 00:14:03.804661 | 
2025-10-01 00:14:03.804765 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-01 00:14:03.826855 | controller | ok
2025-10-01 00:14:03.841297 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-01 00:14:03.848231 | 
2025-10-01 00:14:03.848298 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-01 00:14:04.433068 | controller -> localhost | Generating public/private rsa key pair.
2025-10-01 00:14:04.433394 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_rsa.
2025-10-01 00:14:04.433454 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_rsa.pub.
2025-10-01 00:14:04.433498 | controller -> localhost | The key fingerprint is:
2025-10-01 00:14:04.433539 | controller -> localhost | SHA256:ieoC3T1SZcVE6RvlsS3DcGEV88YA1/+4vMRfX4UhXiQ zuul-build-sshkey
2025-10-01 00:14:04.433578 | controller -> localhost | The key's randomart image is:
2025-10-01 00:14:04.433615 | controller -> localhost | +---[RSA 2048]----+
2025-10-01 00:14:04.433651 | controller -> localhost | |         =+.E+Bo |
2025-10-01 00:14:04.433734 | controller -> localhost | |        o +.++ =.|
2025-10-01 00:14:04.433775 | controller -> localhost | |       o . *.+o =|
2025-10-01 00:14:04.433813 | controller -> localhost | |      .. .o.*o.+.|
2025-10-01 00:14:04.433849 | controller -> localhost | | . . o. S  o.o..o|
2025-10-01 00:14:04.433900 | controller -> localhost | |. . o.o   .  .. o|
2025-10-01 00:14:04.433945 | controller -> localhost | | .  .. .     .o.o|
2025-10-01 00:14:04.433985 | controller -> localhost | |  ..         .o.+|
2025-10-01 00:14:04.434023 | controller -> localhost | |   ..         ..o|
2025-10-01 00:14:04.434066 | controller -> localhost | +----[SHA256]-----+
2025-10-01 00:14:04.434155 | controller -> localhost | ok: Runtime: 0:00:00.086586
2025-10-01 00:14:04.449018 | 
2025-10-01 00:14:04.449151 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-01 00:14:04.499771 | controller | ok
2025-10-01 00:14:04.521391 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-01 00:14:04.534022 | 
2025-10-01 00:14:04.534111 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-01 00:14:04.569487 | controller | skipping: Conditional result was False
2025-10-01 00:14:04.585306 | 
2025-10-01 00:14:04.585461 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-01 00:14:05.093306 | controller | changed
2025-10-01 00:14:05.107024 | 
2025-10-01 00:14:05.107204 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-01 00:14:05.360562 | controller | ok
2025-10-01 00:14:05.374078 | 
2025-10-01 00:14:05.374224 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-01 00:14:06.061510 | controller | changed
2025-10-01 00:14:06.076165 | 
2025-10-01 00:14:06.076424 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-01 00:14:06.792479 | controller | changed
2025-10-01 00:14:06.806232 | 
2025-10-01 00:14:06.806367 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-01 00:14:06.845271 | controller | skipping: Conditional result was False
2025-10-01 00:14:06.861072 | 
2025-10-01 00:14:06.861224 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-01 00:14:07.317840 | controller -> localhost | changed
2025-10-01 00:14:07.334264 | 
2025-10-01 00:14:07.334347 | TASK [add-build-sshkey : Add back temp key]
2025-10-01 00:14:07.664085 | controller -> localhost | Identity added: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_rsa (zuul-build-sshkey)
2025-10-01 00:14:07.664498 | controller -> localhost | ok: Runtime: 0:00:00.013621
2025-10-01 00:14:07.680612 | 
2025-10-01 00:14:07.680779 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-01 00:14:08.058729 | controller | ok
2025-10-01 00:14:08.066486 | 
2025-10-01 00:14:08.066573 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-01 00:14:08.118492 | controller | skipping: Conditional result was False
2025-10-01 00:14:08.135008 | 
2025-10-01 00:14:08.135176 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-01 00:14:08.170343 | controller | ok
2025-10-01 00:14:08.194259 | 
2025-10-01 00:14:08.194452 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-01 00:14:08.476485 | controller -> localhost | ok
2025-10-01 00:14:08.483576 | 
2025-10-01 00:14:08.483660 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-01 00:14:08.517446 | controller | ok
2025-10-01 00:14:08.531066 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-01 00:14:08.540223 | 
2025-10-01 00:14:08.540317 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-01 00:14:08.855480 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-01 00:14:08.855775 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_ecdsa.
2025-10-01 00:14:08.855822 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_ecdsa.pub.
2025-10-01 00:14:08.855865 | controller -> localhost | The key fingerprint is:
2025-10-01 00:14:08.855898 | controller -> localhost | SHA256:/eyTg0LDEPy+9BTmbyqXhLg32Zj6beS7xV6ZVKeMJck zuul-build-sshkey
2025-10-01 00:14:08.855928 | controller -> localhost | The key's randomart image is:
2025-10-01 00:14:08.855956 | controller -> localhost | +---[ECDSA 521]---+
2025-10-01 00:14:08.856007 | controller -> localhost | |     .           |
2025-10-01 00:14:08.856037 | controller -> localhost | |      o    . .   |
2025-10-01 00:14:08.856069 | controller -> localhost | |       o    E . o|
2025-10-01 00:14:08.856135 | controller -> localhost | |      . ..o  = o.|
2025-10-01 00:14:08.856186 | controller -> localhost | |       =S+... +  |
2025-10-01 00:14:08.856223 | controller -> localhost | |      . B =+ . o |
2025-10-01 00:14:08.856251 | controller -> localhost | |       + & +=.+  |
2025-10-01 00:14:08.856280 | controller -> localhost | |      . X.O+*.   |
2025-10-01 00:14:08.856306 | controller -> localhost | |      .+.*==oo   |
2025-10-01 00:14:08.856330 | controller -> localhost | +----[SHA256]-----+
2025-10-01 00:14:08.856407 | controller -> localhost | ok: Runtime: 0:00:00.009565
2025-10-01 00:14:08.869475 | 
2025-10-01 00:14:08.869604 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-01 00:14:08.900836 | controller | ok
2025-10-01 00:14:08.908677 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-01 00:14:08.921450 | 
2025-10-01 00:14:08.921571 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-01 00:14:08.957882 | controller | skipping: Conditional result was False
2025-10-01 00:14:08.968408 | 
2025-10-01 00:14:08.968535 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-01 00:14:09.264159 | controller | changed
2025-10-01 00:14:09.341027 | 
2025-10-01 00:14:09.341238 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-01 00:14:09.586907 | controller | ok
2025-10-01 00:14:09.601406 | 
2025-10-01 00:14:09.601582 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-01 00:14:10.279072 | controller | changed
2025-10-01 00:14:10.292994 | 
2025-10-01 00:14:10.293146 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-01 00:14:10.965622 | controller | changed
2025-10-01 00:14:10.981606 | 
2025-10-01 00:14:10.981830 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-01 00:14:11.020627 | controller | skipping: Conditional result was False
2025-10-01 00:14:11.030450 | 
2025-10-01 00:14:11.030550 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-01 00:14:11.342420 | controller -> localhost | changed
2025-10-01 00:14:11.374491 | 
2025-10-01 00:14:11.374739 | TASK [add-build-sshkey : Add back temp key]
2025-10-01 00:14:11.731647 | controller -> localhost | Identity added: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/e4d7cfab423f4f84ad4d2170749cb49b_id_ecdsa (zuul-build-sshkey)
2025-10-01 00:14:11.732177 | controller -> localhost | ok: Runtime: 0:00:00.016074
2025-10-01 00:14:11.746706 | 
2025-10-01 00:14:11.746869 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-01 00:14:12.000175 | controller | ok
2025-10-01 00:14:12.014106 | 
2025-10-01 00:14:12.014256 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-01 00:14:12.062569 | controller | skipping: Conditional result was False
2025-10-01 00:14:12.089514 | 
2025-10-01 00:14:12.089736 | TASK [include_role : remove-zuul-sshkey]
2025-10-01 00:14:12.127550 | controller | skipping: Conditional result was False
2025-10-01 00:14:12.148125 | 
2025-10-01 00:14:12.148295 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-01 00:14:12.406386 | controller | ok: "logs"
2025-10-01 00:14:12.407267 | controller | ok: All items complete
2025-10-01 00:14:12.407367 | 
2025-10-01 00:14:12.602951 | controller | ok: "artifacts"
2025-10-01 00:14:12.794876 | controller | ok: "docs"
2025-10-01 00:14:12.809416 | 
2025-10-01 00:14:12.809692 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-01 00:14:13.079106 | controller | changed: "logs"
2025-10-01 00:14:13.280181 | controller | changed: "artifacts"
2025-10-01 00:14:13.481158 | controller | changed: "docs"
2025-10-01 00:14:13.530352 | 
2025-10-01 00:14:13.530504 | PLAY RECAP
2025-10-01 00:14:13.530572 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-01 00:14:13.530608 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-01 00:14:13.530632 | 
2025-10-01 00:14:13.702315 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-01 00:14:13.705188 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-01 00:14:14.358433 | 
2025-10-01 00:14:14.358566 | PLAY [all]
2025-10-01 00:14:14.382102 | 
2025-10-01 00:14:14.382224 | TASK [Install binary dependencies]
2025-10-01 00:14:14.471561 | controller | ok
2025-10-01 00:14:14.505374 | 
2025-10-01 00:14:14.505549 | TASK [bindep : Include find tasks]
2025-10-01 00:14:14.540123 | controller | ok
2025-10-01 00:14:14.551651 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-01 00:14:14.560981 | 
2025-10-01 00:14:14.561110 | TASK [bindep : Look for bindep.txt]
2025-10-01 00:14:14.939520 | controller | ok
2025-10-01 00:14:14.952465 | 
2025-10-01 00:14:14.952588 | TASK [bindep : Define bindep_file fact]
2025-10-01 00:14:14.982926 | controller | skipping: Conditional result was False
2025-10-01 00:14:14.993518 | 
2025-10-01 00:14:14.993703 | TASK [bindep : Look for other-requirements.txt]
2025-10-01 00:14:15.230352 | controller | ok
2025-10-01 00:14:15.245048 | 
2025-10-01 00:14:15.245257 | TASK [bindep : Define bindep_file fact]
2025-10-01 00:14:15.288597 | controller | skipping: Conditional result was False
2025-10-01 00:14:15.302294 | 
2025-10-01 00:14:15.302418 | TASK [bindep : Look for bindep fallback file]
2025-10-01 00:14:15.352427 | controller | skipping: Conditional result was False
2025-10-01 00:14:15.363008 | 
2025-10-01 00:14:15.363120 | TASK [bindep : Define bindep_file fact]
2025-10-01 00:14:15.401025 | controller | skipping: Conditional result was False
2025-10-01 00:14:15.410719 | 
2025-10-01 00:14:15.410834 | TASK [bindep : Include bindep tasks]
2025-10-01 00:14:15.448569 | controller | skipping: Conditional result was False
2025-10-01 00:14:15.465494 | 
2025-10-01 00:14:15.465705 | TASK [bindep : Include install tasks]
2025-10-01 00:14:15.504845 | controller | skipping: Conditional result was False
2025-10-01 00:14:15.520249 | 
2025-10-01 00:14:15.520415 | LOOP [bindep : Include package tasks]
2025-10-01 00:14:15.609599 | 
2025-10-01 00:14:15.609977 | TASK [Run test-setup role]
2025-10-01 00:14:15.644434 | controller | ok
2025-10-01 00:14:15.677547 | 
2025-10-01 00:14:15.677769 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-01 00:14:15.917147 | controller | ok
2025-10-01 00:14:15.932840 | 
2025-10-01 00:14:15.933012 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-01 00:14:16.490070 | controller | skipping: Conditional result was False
2025-10-01 00:14:16.522053 | 
2025-10-01 00:14:16.522190 | PLAY RECAP
2025-10-01 00:14:16.522245 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-01 00:14:16.522273 | 
2025-10-01 00:14:16.683999 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-01 00:14:16.685065 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-01 00:14:17.325026 | 
2025-10-01 00:14:17.325218 | PLAY [controller]
2025-10-01 00:14:17.346820 | 
2025-10-01 00:14:17.346959 | TASK [Create the /root directory]
2025-10-01 00:14:17.748057 | controller | ok
2025-10-01 00:14:17.756555 | 
2025-10-01 00:14:17.756659 | TASK [Install glibc-langpack-en]
2025-10-01 00:14:21.764399 | controller | ok: Nothing to do
2025-10-01 00:14:21.778439 | 
2025-10-01 00:14:21.778583 | TASK [Ensure controller directory exists]
2025-10-01 00:14:22.004040 | controller | changed
2025-10-01 00:14:22.018480 | 
2025-10-01 00:14:22.018793 | TASK [Install container runtime]
2025-10-01 00:14:22.099633 | controller | ok
2025-10-01 00:14:22.161181 | 
2025-10-01 00:14:22.161349 | LOOP [ensure-podman : Find distribution installation]
2025-10-01 00:14:22.217114 | controller | ok: "/var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-01 00:14:22.233934 | controller | included: /var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-01 00:14:22.240848 | 
2025-10-01 00:14:22.240919 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-01 00:15:27.705529 | controller | changed
2025-10-01 00:15:27.712659 | 
2025-10-01 00:15:27.712766 | TASK [ensure-podman : Fetch podman version]
2025-10-01 00:15:28.261123 | controller | Client:       Podman Engine
2025-10-01 00:15:28.261212 | controller | Version:      4.6.2
2025-10-01 00:15:28.261256 | controller | API Version:  4.6.2
2025-10-01 00:15:28.261298 | controller | Go Version:   go1.19.12
2025-10-01 00:15:28.261349 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-01 00:15:28.261392 | controller | OS/Arch:      linux/amd64
2025-10-01 00:15:28.747542 | controller | ok: Runtime: 0:00:00.189645
2025-10-01 00:15:28.764055 | 
2025-10-01 00:15:28.764214 | TASK [ensure-podman : Print podman version installed]
2025-10-01 00:15:28.810164 | Podman version: Client:       Podman Engine
2025-10-01 00:15:28.810464 | Version:      4.6.2
2025-10-01 00:15:28.810538 | API Version:  4.6.2
2025-10-01 00:15:28.810599 | Go Version:   go1.19.12
2025-10-01 00:15:28.810642 | Built:        Mon Aug 28 19:38:31 2023
2025-10-01 00:15:28.810754 | OS/Arch:      linux/amd64
2025-10-01 00:15:28.826190 | 
2025-10-01 00:15:28.826354 | TASK [ensure-podman : Validate podman engine]
2025-10-01 00:15:29.377978 | controller | skipping: Conditional result was False
2025-10-01 00:15:29.397230 | 
2025-10-01 00:15:29.397529 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-01 00:15:29.428910 | controller | skipping: Conditional result was False
2025-10-01 00:15:29.460761 | 
2025-10-01 00:15:29.460982 | TASK [Ensure python3.8 is present]
2025-10-01 00:15:29.478824 | controller | skipping: Conditional result was False
2025-10-01 00:15:29.490587 | 
2025-10-01 00:15:29.490736 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-01 00:15:29.519213 | controller | ok
2025-10-01 00:15:29.552147 | 
2025-10-01 00:15:29.552318 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-01 00:15:30.987388 | controller | ok: Nothing to do
2025-10-01 00:15:30.995707 | 
2025-10-01 00:15:30.995836 | TASK [our-ensure-python : Also install python3-devel]
2025-10-01 00:15:39.704940 | controller | changed
2025-10-01 00:15:39.730155 | 
2025-10-01 00:15:39.730348 | TASK [Run ensure-virtualenv role]
2025-10-01 00:15:39.770148 | controller | ok
2025-10-01 00:15:39.807642 | 
2025-10-01 00:15:39.807856 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-01 00:15:40.064499 | controller | /usr/bin/virtualenv
2025-10-01 00:15:40.388820 | controller | ok: Runtime: 0:00:00.004655
2025-10-01 00:15:40.399005 | 
2025-10-01 00:15:40.399104 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-01 00:15:40.435793 | controller | skipping: Conditional result was False
2025-10-01 00:15:40.436086 | controller | ok: All items complete
2025-10-01 00:15:40.436121 | 
2025-10-01 00:15:40.448840 | 
2025-10-01 00:15:40.448985 | TASK [Find the full path of the Python interpreter]
2025-10-01 00:15:40.677918 | controller | /usr/bin/python3
2025-10-01 00:15:40.982181 | controller | ok
2025-10-01 00:15:40.996852 | 
2025-10-01 00:15:40.997061 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-01 00:15:41.864005 | controller | created virtual environment CPython3.11.0.final.0-64 in 495ms
2025-10-01 00:15:41.881543 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-01 00:15:41.881596 | 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)
2025-10-01 00:15:41.881606 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-01 00:15:41.881621 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-01 00:15:42.063282 | controller | changed
2025-10-01 00:15:42.079888 | 
2025-10-01 00:15:42.080060 | TASK [Set selinux package]
2025-10-01 00:15:42.123027 | controller | ok
2025-10-01 00:15:42.131179 | 
2025-10-01 00:15:42.131272 | TASK [Set selinux package (Fedora)]
2025-10-01 00:15:42.183498 | controller | ok
2025-10-01 00:15:42.196280 | 
2025-10-01 00:15:42.196564 | TASK [Install selinux into virtualenv]
2025-10-01 00:16:07.691514 | controller | Collecting selinux-please-lie-to-me
2025-10-01 00:16:19.934895 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-01 00:16:20.256181 | controller | Collecting setuptools<50.0.0
2025-10-01 00:16:20.262553 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-01 00:16:20.331689 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 12.6 MB/s eta 0:00:00
2025-10-01 00:16:20.417282 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-01 00:16:20.417448 | controller |   Attempting uninstall: setuptools
2025-10-01 00:16:20.419944 | controller |     Found existing installation: setuptools 62.6.0
2025-10-01 00:16:20.478984 | controller |     Uninstalling setuptools-62.6.0:
2025-10-01 00:16:20.486949 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-01 00:16:20.826615 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-01 00:16:32.301380 | controller |
2025-10-01 00:16:32.381432 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-01 00:16:32.381464 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-01 00:16:32.764897 | controller | ok: Runtime: 0:00:49.965404
2025-10-01 00:16:32.775213 | 
2025-10-01 00:16:32.775328 | TASK [Install pytest-forked into virtualenv]
2025-10-01 00:16:41.489046 | controller | Collecting pytest-forked
2025-10-01 00:16:53.848565 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-01 00:16:53.889796 | controller | Collecting py
2025-10-01 00:16:53.894536 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-01 00:16:53.918170 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.7 MB/s eta 0:00:00
2025-10-01 00:16:54.026453 | controller | Collecting pytest>=3.10
2025-10-01 00:16:54.032287 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-01 00:16:54.048833 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 30.0 MB/s eta 0:00:00
2025-10-01 00:16:54.087086 | controller | Collecting iniconfig>=1
2025-10-01 00:16:54.090815 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-01 00:16:54.132213 | controller | Collecting packaging>=20
2025-10-01 00:16:54.135918 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-01 00:16:54.142358 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 12.9 MB/s eta 0:00:00
2025-10-01 00:16:54.172768 | controller | Collecting pluggy<2,>=1.5
2025-10-01 00:16:54.176273 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-01 00:16:54.227228 | controller | Collecting pygments>=2.7.2
2025-10-01 00:16:54.230551 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-01 00:16:54.272675 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 32.0 MB/s eta 0:00:00
2025-10-01 00:16:54.344002 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-01 00:16:55.441939 | controller | Successfully installed iniconfig-2.1.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-10-01 00:16:55.450445 | controller |
2025-10-01 00:16:55.516968 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-01 00:16:55.517001 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-01 00:16:55.829835 | controller | ok: Runtime: 0:00:22.512623
2025-10-01 00:16:55.839080 | 
2025-10-01 00:16:55.839179 | TASK [Update pip]
2025-10-01 00:16:56.371471 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-01 00:17:18.209319 | controller | Collecting pip
2025-10-01 00:17:30.390981 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-01 00:17:30.501103 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 16.7 MB/s eta 0:00:00
2025-10-01 00:17:30.564132 | controller | Installing collected packages: pip
2025-10-01 00:17:30.564348 | controller |   Attempting uninstall: pip
2025-10-01 00:17:30.566514 | controller |     Found existing installation: pip 22.2.2
2025-10-01 00:17:30.702920 | controller |     Uninstalling pip-22.2.2:
2025-10-01 00:17:30.717676 | controller |       Successfully uninstalled pip-22.2.2
2025-10-01 00:17:31.534690 | controller | Successfully installed pip-25.2
2025-10-01 00:17:32.011966 | controller | ok: Runtime: 0:00:35.536229
2025-10-01 00:17:32.025996 | 
2025-10-01 00:17:32.026158 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-01 00:17:32.271887 | controller | changed
2025-10-01 00:17:32.287627 | 
2025-10-01 00:17:32.287854 | TASK [Install ansible into virtualenv]
2025-10-01 00:17:32.846449 | controller | Processing ./src/github.com/ansible/ansible
2025-10-01 00:17:32.849681 | controller |   Installing build dependencies: started
2025-10-01 00:17:55.362776 | controller |   Installing build dependencies: finished with status 'done'
2025-10-01 00:17:55.364138 | controller |   Getting requirements to build wheel: started
2025-10-01 00:17:56.086420 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-01 00:17:56.087262 | controller |   Preparing metadata (pyproject.toml): started
2025-10-01 00:17:56.534451 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-01 00:17:56.540075 | 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.
2025-10-01 00:17:56.545547 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-01 00:17:56.893075 | controller | ERROR
2025-10-01 00:17:56.893251 | controller | {
2025-10-01 00:17:56.893289 | controller |   "delta": "0:00:24.066824",
2025-10-01 00:17:56.893316 | controller |   "end": "2025-10-01 00:17:56.608734",
2025-10-01 00:17:56.893339 | controller |   "msg": "non-zero return code",
2025-10-01 00:17:56.893374 | controller |   "rc": 1,
2025-10-01 00:17:56.893397 | controller |   "start": "2025-10-01 00:17:32.541910"
2025-10-01 00:17:56.893418 | controller | }
failure
2025-10-01 00:17:56.895605 | 
2025-10-01 00:17:56.895654 | PLAY RECAP
2025-10-01 00:17:56.895721 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-01 00:17:56.895743 | 
2025-10-01 00:17:57.032555 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-01 00:17:57.033956 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-01 00:17:57.704541 | 
2025-10-01 00:17:57.704718 | PLAY [all]
2025-10-01 00:17:57.726582 | 
2025-10-01 00:17:57.726686 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-01 00:17:58.007230 | controller | changed: non-zero return code
2025-10-01 00:17:58.015480 | 
2025-10-01 00:17:58.015613 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-01 00:17:58.041534 | controller | skipping: Conditional result was False
2025-10-01 00:17:58.057447 | 
2025-10-01 00:17:58.057632 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-01 00:17:58.095892 | 
2025-10-01 00:17:58.096140 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-01 00:17:58.131402 | 
2025-10-01 00:17:58.131641 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-01 00:17:58.157034 | controller | skipping: Conditional result was False
2025-10-01 00:17:58.168196 | 
2025-10-01 00:17:58.168305 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-01 00:17:58.203917 | 
2025-10-01 00:17:58.204178 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-01 00:17:58.229978 | controller | skipping: Conditional result was False
2025-10-01 00:17:58.239276 | 
2025-10-01 00:17:58.239380 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-01 00:17:58.264898 | controller | skipping: Conditional result was False
2025-10-01 00:17:58.273688 | 
2025-10-01 00:17:58.273803 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-01 00:17:58.299073 | controller | skipping: Conditional result was False
2025-10-01 00:17:58.346572 | 
2025-10-01 00:17:58.346744 | PLAY RECAP
2025-10-01 00:17:58.346816 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-01 00:17:58.346839 | 
2025-10-01 00:17:58.470898 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-01 00:17:58.472661 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-01 00:17:59.118112 | 
2025-10-01 00:17:59.118241 | PLAY [all:!appliance*]
2025-10-01 00:17:59.141383 | 
2025-10-01 00:17:59.141490 | TASK [unregister the node]
2025-10-01 00:17:59.676347 | controller | skipping: Conditional result was False
2025-10-01 00:17:59.691292 | 
2025-10-01 00:17:59.691541 | TASK [include_role : fetch-output]
2025-10-01 00:17:59.753292 | controller | ok
2025-10-01 00:17:59.791232 | 
2025-10-01 00:17:59.791328 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-01 00:17:59.878726 | controller | skipping: Conditional result was False
2025-10-01 00:17:59.893549 | 
2025-10-01 00:17:59.893750 | TASK [fetch-output : Set log path for single node]
2025-10-01 00:17:59.958422 | controller | ok
2025-10-01 00:17:59.971998 | 
2025-10-01 00:17:59.972135 | LOOP [fetch-output : Ensure local output dirs]
2025-10-01 00:18:00.437435 | controller -> localhost | ok: "/var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/logs"
2025-10-01 00:18:00.751538 | controller -> localhost | changed: "/var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/artifacts"
2025-10-01 00:18:01.037500 | controller -> localhost | changed: "/var/lib/zuul/builds/e4d7cfab423f4f84ad4d2170749cb49b/work/docs"
2025-10-01 00:18:01.057461 | 
2025-10-01 00:18:01.057610 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-01 00:18:01.815567 | controller | changed:
2025-10-01 00:18:01.816071 | controller | .d..t...... ./
2025-10-01 00:18:01.816176 | controller | cd+++++++++ controller/
2025-10-01 00:18:01.816292 | controller | changed: All items complete
2025-10-01 00:18:01.816375 | 
2025-10-01 00:18:02.324548 | controller | changed: .d..t...... ./
2025-10-01 00:18:02.845510 | controller | changed: .d..t...... ./
2025-10-01 00:18:02.875618 | 
2025-10-01 00:18:02.875936 | TASK [include_role : fetch-output-openshift]
2025-10-01 00:18:02.904814 | controller | skipping: Conditional result was False
2025-10-01 00:18:02.921575 | 
2025-10-01 00:18:02.921766 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-01 00:18:02.966809 | controller | skipping: Conditional result was False
2025-10-01 00:18:02.978068 | controller | skipping: Conditional result was False
2025-10-01 00:18:03.020336 | 
2025-10-01 00:18:03.020552 | PLAY [localhost]
2025-10-01 00:18:03.038619 | 
2025-10-01 00:18:03.038753 | TASK [Run Zuul manifest role]
2025-10-01 00:18:03.070171 | localhost | ok
2025-10-01 00:18:03.089047 | 
2025-10-01 00:18:03.089181 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-01 00:18:03.607545 | localhost | changed
2025-10-01 00:18:03.619182 | 
2025-10-01 00:18:03.619381 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-01 00:18:03.671797 | localhost | ok
2025-10-01 00:18:03.690916 | 
2025-10-01 00:18:03.691067 | TASK [Set zuul-log-path fact]
2025-10-01 00:18:03.731599 | localhost | ok
2025-10-01 00:18:03.757005 | 
2025-10-01 00:18:03.757137 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 00:18:03.800638 | localhost | ok
2025-10-01 00:18:03.812406 | 
2025-10-01 00:18:03.812516 | LOOP [Run upload-logs-swift role]
2025-10-01 00:18:03.860208 | localhost | Output suppressed because no_log was given
2025-10-01 00:18:03.898093 | 
2025-10-01 00:18:03.898200 | TASK [Set zuul-log-path fact]
2025-10-01 00:18:03.986500 | localhost | skipping: Conditional result was False
2025-10-01 00:18:04.049073 | 
2025-10-01 00:18:04.049253 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-01 00:18:04.514458 | localhost -> localhost | ok: Runtime: 0:00:00.009873
2025-10-01 00:18:04.526750 | 
2025-10-01 00:18:04.526953 | TASK [upload-logs-swift : Upload logs to swift]