2026-01-21 00:06:37.260706 | Job console starting...
2026-01-21 00:06:37.279793 | Updating repositories
2026-01-21 00:06:37.397495 | Preparing job workspace
2026-01-21 00:06:53.494695 | Running Ansible setup...
2026-01-21 00:07:00.359798 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:07:00.967769 | 
2026-01-21 00:07:00.967918 | PLAY [localhost]
2026-01-21 00:07:00.981885 | 
2026-01-21 00:07:00.982004 | TASK [Gathering Facts]
2026-01-21 00:07:01.981997 | localhost | ok
2026-01-21 00:07:02.018856 | 
2026-01-21 00:07:02.019348 | TASK [Setup log path fact]
2026-01-21 00:07:02.042165 | localhost | ok
2026-01-21 00:07:02.063496 | 
2026-01-21 00:07:02.063647 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:07:02.095511 | localhost | ok
2026-01-21 00:07:02.108107 | 
2026-01-21 00:07:02.108257 | TASK [emit-job-header : Print job information]
2026-01-21 00:07:02.161990 | # Job Information
2026-01-21 00:07:02.162294 | Ansible Version: 2.15.12
2026-01-21 00:07:02.162453 | Job: ansible-test-sanity-docker-devel
2026-01-21 00:07:02.162484 | Pipeline: periodic
2026-01-21 00:07:02.162504 | Executor: ze03.softwarefactory-project.io
2026-01-21 00:07:02.162524 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-21 00:07:02.162545 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/c89/ansible/c8927f9a4dbe4884a456091086ee8eb8/
2026-01-21 00:07:02.162564 | Event ID: 08cfdb9560914df89453f509f8798614
2026-01-21 00:07:02.166955 | 
2026-01-21 00:07:02.167038 | LOOP [emit-job-header : Print node information]
2026-01-21 00:07:02.329575 | localhost | ok:
2026-01-21 00:07:02.329812 | localhost | # Node Information
2026-01-21 00:07:02.329842 | localhost | Inventory Hostname: controller
2026-01-21 00:07:02.329863 | localhost | Hostname: np0005589718
2026-01-21 00:07:02.329883 | localhost | Username: zuul
2026-01-21 00:07:02.329907 | localhost | Distro: Fedora 37
2026-01-21 00:07:02.329927 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-21 00:07:02.329945 | localhost | Region: ca-ymq-1
2026-01-21 00:07:02.329962 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-21 00:07:02.329979 | localhost | Product Name: OpenStack Nova
2026-01-21 00:07:02.330002 | localhost | Interface IP: 162.253.55.227
2026-01-21 00:07:02.353304 | 
2026-01-21 00:07:02.353540 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-21 00:07:02.787177 | localhost -> localhost | changed
2026-01-21 00:07:02.792875 | 
2026-01-21 00:07:02.792944 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-21 00:07:03.733181 | localhost -> localhost | changed
2026-01-21 00:07:03.753134 | 
2026-01-21 00:07:03.753213 | PLAY [all:!appliance*]
2026-01-21 00:07:03.769429 | 
2026-01-21 00:07:03.769514 | TASK [include_role : start-zuul-console]
2026-01-21 00:07:03.792568 | controller | ok
2026-01-21 00:07:03.808226 | 
2026-01-21 00:07:03.808303 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-21 00:07:04.255892 | controller | ok
2026-01-21 00:07:04.285618 | 
2026-01-21 00:07:04.285765 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-21 00:07:26.393684 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-21 00:07:26.409123 | 
2026-01-21 00:07:26.409382 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-21 00:07:26.958149 | controller | skipping: Conditional result was False
2026-01-21 00:07:26.969960 | 
2026-01-21 00:07:26.970180 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-21 00:07:27.004125 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.015546 | 
2026-01-21 00:07:27.015674 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-21 00:07:27.043947 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.056172 | 
2026-01-21 00:07:27.056396 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-21 00:07:27.083594 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.094025 | 
2026-01-21 00:07:27.094186 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-21 00:07:27.121173 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.131173 | 
2026-01-21 00:07:27.131307 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-21 00:07:27.158077 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.175609 | 
2026-01-21 00:07:27.175774 | TASK [Disable Fedora Modular]
2026-01-21 00:07:27.450148 | controller | changed
2026-01-21 00:07:27.469219 | 
2026-01-21 00:07:27.469467 | TASK [Enable EPEL]
2026-01-21 00:07:27.508871 | controller | skipping: Conditional result was False
2026-01-21 00:07:27.520228 | 
2026-01-21 00:07:27.520357 | TASK [Register the RHEL node]
2026-01-21 00:07:28.085582 | 
2026-01-21 00:07:28.085875 | TASK [Show the subscription-manager status]
2026-01-21 00:07:28.633909 | controller | skipping: Conditional result was False
2026-01-21 00:07:28.650144 | 
2026-01-21 00:07:28.650381 | TASK [Enable EPEL on RHEL]
2026-01-21 00:07:29.188978 | controller | skipping: Conditional result was False
2026-01-21 00:07:29.196648 | 
2026-01-21 00:07:29.196802 | TASK [Install git and tox]
2026-01-21 00:08:17.222063 | controller | changed
2026-01-21 00:08:17.232518 | 
2026-01-21 00:08:17.232962 | TASK [include_role : prepare-workspace]
2026-01-21 00:08:17.265921 | controller | ok
2026-01-21 00:08:17.395829 | 
2026-01-21 00:08:17.395981 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-21 00:08:17.670944 | controller | ok
2026-01-21 00:08:17.685482 | 
2026-01-21 00:08:17.685631 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-21 00:08:36.549107 | controller | Output suppressed because no_log was given
2026-01-21 00:08:36.588509 | 
2026-01-21 00:08:36.588661 | TASK [include_role : prepare-workspace-openshift]
2026-01-21 00:08:36.621620 | controller | skipping: Conditional result was False
2026-01-21 00:08:36.675883 | 
2026-01-21 00:08:36.675969 | PLAY [all:!appliance]
2026-01-21 00:08:36.694037 | 
2026-01-21 00:08:36.694120 | TASK [Run add-build-sshkey role (RSA)]
2026-01-21 00:08:36.724847 | controller | ok
2026-01-21 00:08:36.783441 | 
2026-01-21 00:08:36.783598 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:08:37.125105 | controller -> localhost | ok
2026-01-21 00:08:37.132081 | 
2026-01-21 00:08:37.132167 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:08:37.153770 | controller | ok
2026-01-21 00:08:37.256686 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:08:37.263139 | 
2026-01-21 00:08:37.263204 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:08:38.002021 | controller -> localhost | Generating public/private rsa key pair.
2026-01-21 00:08:38.002199 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_rsa.
2026-01-21 00:08:38.002228 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_rsa.pub.
2026-01-21 00:08:38.002249 | controller -> localhost | The key fingerprint is:
2026-01-21 00:08:38.002268 | controller -> localhost | SHA256:doBu6na2apFtLCRy2CcOXI1DnHO+CrVGck5NhY1H+Jc zuul-build-sshkey
2026-01-21 00:08:38.002287 | controller -> localhost | The key's randomart image is:
2026-01-21 00:08:38.002305 | controller -> localhost | +---[RSA 2048]----+
2026-01-21 00:08:38.002323 | controller -> localhost | |  o.+ Bo         |
2026-01-21 00:08:38.002344 | controller -> localhost | |   B B +         |
2026-01-21 00:08:38.002364 | controller -> localhost | |.o. B + . .      |
2026-01-21 00:08:38.002382 | controller -> localhost | |+o==o+ . E       |
2026-01-21 00:08:38.002398 | controller -> localhost | | =B=.++ S .      |
2026-01-21 00:08:38.002422 | controller -> localhost | | ..++++. .       |
2026-01-21 00:08:38.002444 | controller -> localhost | |  o o+           |
2026-01-21 00:08:38.002463 | controller -> localhost | |   oo o          |
2026-01-21 00:08:38.002481 | controller -> localhost | |   oo+..         |
2026-01-21 00:08:38.002501 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:08:38.002544 | controller -> localhost | ok: Runtime: 0:00:00.251820
2026-01-21 00:08:38.049401 | 
2026-01-21 00:08:38.049538 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:08:38.080107 | controller | ok
2026-01-21 00:08:38.154523 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:08:38.168821 | 
2026-01-21 00:08:38.168954 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:08:38.196309 | controller | skipping: Conditional result was False
2026-01-21 00:08:38.205409 | 
2026-01-21 00:08:38.205499 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:08:38.594607 | controller | changed
2026-01-21 00:08:38.603326 | 
2026-01-21 00:08:38.603454 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:08:38.843879 | controller | ok
2026-01-21 00:08:38.855548 | 
2026-01-21 00:08:38.855699 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:08:39.495262 | controller | changed
2026-01-21 00:08:39.504839 | 
2026-01-21 00:08:39.505017 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:08:40.120957 | controller | changed
2026-01-21 00:08:40.127262 | 
2026-01-21 00:08:40.127353 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:08:40.141957 | controller | skipping: Conditional result was False
2026-01-21 00:08:40.150096 | 
2026-01-21 00:08:40.150199 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:08:40.559107 | controller -> localhost | changed
2026-01-21 00:08:40.579137 | 
2026-01-21 00:08:40.579280 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:08:40.910107 | controller -> localhost | Identity added: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_rsa (zuul-build-sshkey)
2026-01-21 00:08:40.910421 | controller -> localhost | ok: Runtime: 0:00:00.007738
2026-01-21 00:08:40.917652 | 
2026-01-21 00:08:40.917749 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:08:41.248088 | controller | ok
2026-01-21 00:08:41.263788 | 
2026-01-21 00:08:41.263935 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:08:41.303528 | controller | skipping: Conditional result was False
2026-01-21 00:08:41.318598 | 
2026-01-21 00:08:41.318718 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-21 00:08:41.349350 | controller | ok
2026-01-21 00:08:41.381021 | 
2026-01-21 00:08:41.381155 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:08:41.682130 | controller -> localhost | ok
2026-01-21 00:08:41.688944 | 
2026-01-21 00:08:41.689240 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:08:41.727001 | controller | ok
2026-01-21 00:08:41.755814 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:08:41.762800 | 
2026-01-21 00:08:41.762877 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:08:42.184290 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-21 00:08:42.184541 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_ecdsa.
2026-01-21 00:08:42.184572 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_ecdsa.pub.
2026-01-21 00:08:42.184614 | controller -> localhost | The key fingerprint is:
2026-01-21 00:08:42.184635 | controller -> localhost | SHA256:DtCsuvYyqhdljzX8/ahEF6vRRYEmLfoh4sFUIBwumWQ zuul-build-sshkey
2026-01-21 00:08:42.184655 | controller -> localhost | The key's randomart image is:
2026-01-21 00:08:42.184673 | controller -> localhost | +---[ECDSA 521]---+
2026-01-21 00:08:42.184693 | controller -> localhost | | Eo..o.  . .o.   |
2026-01-21 00:08:42.184711 | controller -> localhost | |o+...o  o +.     |
2026-01-21 00:08:42.184751 | controller -> localhost | |+ .o..o. +. .    |
2026-01-21 00:08:42.184770 | controller -> localhost | | .  *o* .. +     |
2026-01-21 00:08:42.184788 | controller -> localhost | |   +.*.=So+      |
2026-01-21 00:08:42.184819 | controller -> localhost | |  ..o .+o+.      |
2026-01-21 00:08:42.184837 | controller -> localhost | |  ..    +  o     |
2026-01-21 00:08:42.184861 | controller -> localhost | |  =.   .  . .    |
2026-01-21 00:08:42.184879 | controller -> localhost | |++.+.   ..       |
2026-01-21 00:08:42.184897 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:08:42.184942 | controller -> localhost | ok: Runtime: 0:00:00.018214
2026-01-21 00:08:42.193499 | 
2026-01-21 00:08:42.193635 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:08:42.231834 | controller | ok
2026-01-21 00:08:42.252141 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:08:42.264892 | 
2026-01-21 00:08:42.265011 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:08:42.311606 | controller | skipping: Conditional result was False
2026-01-21 00:08:42.319277 | 
2026-01-21 00:08:42.319392 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:08:42.595411 | controller | changed
2026-01-21 00:08:42.606596 | 
2026-01-21 00:08:42.606700 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:08:42.822110 | controller | ok
2026-01-21 00:08:42.827833 | 
2026-01-21 00:08:42.827904 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:08:43.512041 | controller | changed
2026-01-21 00:08:43.519232 | 
2026-01-21 00:08:43.519325 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:08:44.137767 | controller | changed
2026-01-21 00:08:44.143804 | 
2026-01-21 00:08:44.143883 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:08:44.167943 | controller | skipping: Conditional result was False
2026-01-21 00:08:44.174575 | 
2026-01-21 00:08:44.174673 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:08:44.413681 | controller -> localhost | changed
2026-01-21 00:08:44.426258 | 
2026-01-21 00:08:44.426353 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:08:44.749690 | controller -> localhost | Identity added: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/c8927f9a4dbe4884a456091086ee8eb8_id_ecdsa (zuul-build-sshkey)
2026-01-21 00:08:44.749995 | controller -> localhost | ok: Runtime: 0:00:00.011315
2026-01-21 00:08:44.757228 | 
2026-01-21 00:08:44.757309 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:08:44.954300 | controller | ok
2026-01-21 00:08:44.963906 | 
2026-01-21 00:08:44.964034 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:08:44.991705 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.009675 | 
2026-01-21 00:08:45.009906 | TASK [include_role : remove-zuul-sshkey]
2026-01-21 00:08:45.024948 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.033132 | 
2026-01-21 00:08:45.033242 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-21 00:08:45.283669 | controller | ok: "logs"
2026-01-21 00:08:45.284070 | controller | ok: All items complete
2026-01-21 00:08:45.284118 | 
2026-01-21 00:08:45.460285 | controller | ok: "artifacts"
2026-01-21 00:08:45.644063 | controller | ok: "docs"
2026-01-21 00:08:45.662940 | 
2026-01-21 00:08:45.663062 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-21 00:08:45.913302 | controller | changed: "logs"
2026-01-21 00:08:46.116592 | controller | changed: "artifacts"
2026-01-21 00:08:46.377440 | controller | changed: "docs"
2026-01-21 00:08:46.416848 | 
2026-01-21 00:08:46.416951 | PLAY RECAP
2026-01-21 00:08:46.416991 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-21 00:08:46.417016 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-21 00:08:46.417033 | 
2026-01-21 00:08:46.577516 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:08:46.578650 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:08:47.188321 | 
2026-01-21 00:08:47.188452 | PLAY [all]
2026-01-21 00:08:47.215832 | 
2026-01-21 00:08:47.215960 | TASK [Install binary dependencies]
2026-01-21 00:08:47.276198 | controller | ok
2026-01-21 00:08:47.297597 | 
2026-01-21 00:08:47.297754 | TASK [bindep : Include find tasks]
2026-01-21 00:08:47.331808 | controller | ok
2026-01-21 00:08:47.340070 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-21 00:08:47.346514 | 
2026-01-21 00:08:47.346581 | TASK [bindep : Look for bindep.txt]
2026-01-21 00:08:47.753317 | controller | ok
2026-01-21 00:08:47.766286 | 
2026-01-21 00:08:47.766397 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:47.810866 | controller | skipping: Conditional result was False
2026-01-21 00:08:47.818629 | 
2026-01-21 00:08:47.818771 | TASK [bindep : Look for other-requirements.txt]
2026-01-21 00:08:48.060157 | controller | ok
2026-01-21 00:08:48.069995 | 
2026-01-21 00:08:48.070117 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:48.114653 | controller | skipping: Conditional result was False
2026-01-21 00:08:48.121845 | 
2026-01-21 00:08:48.121936 | TASK [bindep : Look for bindep fallback file]
2026-01-21 00:08:48.178300 | controller | skipping: Conditional result was False
2026-01-21 00:08:48.186638 | 
2026-01-21 00:08:48.186785 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:48.216051 | controller | skipping: Conditional result was False
2026-01-21 00:08:48.223247 | 
2026-01-21 00:08:48.223378 | TASK [bindep : Include bindep tasks]
2026-01-21 00:08:48.290421 | controller | skipping: Conditional result was False
2026-01-21 00:08:48.297381 | 
2026-01-21 00:08:48.297486 | TASK [bindep : Include install tasks]
2026-01-21 00:08:48.344027 | controller | skipping: Conditional result was False
2026-01-21 00:08:48.350416 | 
2026-01-21 00:08:48.350521 | LOOP [bindep : Include package tasks]
2026-01-21 00:08:48.455884 | 
2026-01-21 00:08:48.456088 | TASK [Run test-setup role]
2026-01-21 00:08:48.481383 | controller | ok
2026-01-21 00:08:48.515080 | 
2026-01-21 00:08:48.515206 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-21 00:08:48.792177 | controller | ok
2026-01-21 00:08:48.821666 | 
2026-01-21 00:08:48.821815 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-21 00:08:49.392537 | controller | skipping: Conditional result was False
2026-01-21 00:08:49.446249 | 
2026-01-21 00:08:49.446347 | PLAY RECAP
2026-01-21 00:08:49.446389 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:08:49.446410 | 
2026-01-21 00:08:49.622860 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:08:49.623687 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:08:50.404557 | 
2026-01-21 00:08:50.404686 | PLAY [controller]
2026-01-21 00:08:50.441683 | 
2026-01-21 00:08:50.441856 | TASK [Create the /root directory]
2026-01-21 00:08:50.964478 | controller | ok
2026-01-21 00:08:50.972953 | 
2026-01-21 00:08:50.973110 | TASK [Install glibc-langpack-en]
2026-01-21 00:08:55.335347 | controller | ok: Nothing to do
2026-01-21 00:08:55.363082 | 
2026-01-21 00:08:55.363273 | TASK [Ensure controller directory exists]
2026-01-21 00:08:55.592885 | controller | changed
2026-01-21 00:08:55.601197 | 
2026-01-21 00:08:55.601385 | TASK [Install container runtime]
2026-01-21 00:08:55.685508 | controller | ok
2026-01-21 00:08:55.734969 | 
2026-01-21 00:08:55.735116 | LOOP [ensure-podman : Find distribution installation]
2026-01-21 00:08:55.773434 | controller | ok: "/var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-21 00:08:55.790605 | controller | included: /var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-21 00:08:55.798197 | 
2026-01-21 00:08:55.798287 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-21 00:10:06.840456 | controller | changed
2026-01-21 00:10:06.854659 | 
2026-01-21 00:10:06.854814 | TASK [ensure-podman : Fetch podman version]
2026-01-21 00:10:07.400159 | controller | Client:       Podman Engine
2026-01-21 00:10:07.400256 | controller | Version:      4.6.2
2026-01-21 00:10:07.400301 | controller | API Version:  4.6.2
2026-01-21 00:10:07.400342 | controller | Go Version:   go1.19.12
2026-01-21 00:10:07.400394 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:10:07.400436 | controller | OS/Arch:      linux/amd64
2026-01-21 00:10:07.891234 | controller | ok: Runtime: 0:00:00.181976
2026-01-21 00:10:07.902252 | 
2026-01-21 00:10:07.902391 | TASK [ensure-podman : Print podman version installed]
2026-01-21 00:10:07.960197 | Podman version: Client:       Podman Engine
2026-01-21 00:10:07.960360 | Version:      4.6.2
2026-01-21 00:10:07.960390 | API Version:  4.6.2
2026-01-21 00:10:07.960411 | Go Version:   go1.19.12
2026-01-21 00:10:07.960430 | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:10:07.960450 | OS/Arch:      linux/amd64
2026-01-21 00:10:07.968971 | 
2026-01-21 00:10:07.969092 | TASK [ensure-podman : Validate podman engine]
2026-01-21 00:10:08.507513 | controller | skipping: Conditional result was False
2026-01-21 00:10:08.517187 | 
2026-01-21 00:10:08.517333 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-21 00:10:08.532363 | controller | skipping: Conditional result was False
2026-01-21 00:10:08.551477 | 
2026-01-21 00:10:08.551610 | TASK [Ensure python3.8 is present]
2026-01-21 00:10:08.577590 | controller | skipping: Conditional result was False
2026-01-21 00:10:08.586305 | 
2026-01-21 00:10:08.586408 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-21 00:10:08.610585 | controller | ok
2026-01-21 00:10:08.641108 | 
2026-01-21 00:10:08.641265 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-21 00:10:10.102665 | controller | ok: Nothing to do
2026-01-21 00:10:10.109117 | 
2026-01-21 00:10:10.109201 | TASK [our-ensure-python : Also install python3-devel]
2026-01-21 00:10:20.100319 | controller | changed
2026-01-21 00:10:20.115503 | 
2026-01-21 00:10:20.115617 | TASK [Run ensure-virtualenv role]
2026-01-21 00:10:20.138183 | controller | ok
2026-01-21 00:10:20.164289 | 
2026-01-21 00:10:20.164400 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-21 00:10:20.408763 | controller | /usr/bin/virtualenv
2026-01-21 00:10:20.727473 | controller | ok: Runtime: 0:00:00.004307
2026-01-21 00:10:20.733780 | 
2026-01-21 00:10:20.733849 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-21 00:10:20.763646 | controller | skipping: Conditional result was False
2026-01-21 00:10:20.764091 | controller | ok: All items complete
2026-01-21 00:10:20.764134 | 
2026-01-21 00:10:20.791382 | 
2026-01-21 00:10:20.791571 | TASK [Find the full path of the Python interpreter]
2026-01-21 00:10:21.011956 | controller | /usr/bin/python3
2026-01-21 00:10:21.336261 | controller | ok
2026-01-21 00:10:21.351936 | 
2026-01-21 00:10:21.352176 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-21 00:10:22.216934 | controller | created virtual environment CPython3.11.0.final.0-64 in 511ms
2026-01-21 00:10:22.239196 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-21 00:10:22.239621 | 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-21 00:10:22.239875 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-21 00:10:22.240084 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-21 00:10:22.417721 | controller | changed
2026-01-21 00:10:22.427776 | 
2026-01-21 00:10:22.427922 | TASK [Set selinux package]
2026-01-21 00:10:22.454435 | controller | ok
2026-01-21 00:10:22.462467 | 
2026-01-21 00:10:22.462574 | TASK [Set selinux package (Fedora)]
2026-01-21 00:10:22.505029 | controller | ok
2026-01-21 00:10:22.511099 | 
2026-01-21 00:10:22.511214 | TASK [Install selinux into virtualenv]
2026-01-21 00:10:47.977480 | controller | Collecting selinux-please-lie-to-me
2026-01-21 00:11:00.231171 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-21 00:11:00.554857 | controller | Collecting setuptools<50.0.0
2026-01-21 00:11:00.565688 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-21 00:11:00.599786 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.8 MB/s eta 0:00:00
2026-01-21 00:11:00.677904 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-21 00:11:00.678120 | controller |   Attempting uninstall: setuptools
2026-01-21 00:11:00.680564 | controller |     Found existing installation: setuptools 62.6.0
2026-01-21 00:11:00.749020 | controller |     Uninstalling setuptools-62.6.0:
2026-01-21 00:11:00.757367 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-21 00:11:01.121186 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-21 00:11:12.606073 | controller |
2026-01-21 00:11:12.707554 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:11:12.707600 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:11:13.072288 | controller | ok: Runtime: 0:00:49.993876
2026-01-21 00:11:13.079510 | 
2026-01-21 00:11:13.079613 | TASK [Install pytest-forked into virtualenv]
2026-01-21 00:11:24.886323 | controller | Collecting pytest-forked
2026-01-21 00:11:37.224133 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-21 00:11:37.280310 | controller | Collecting py
2026-01-21 00:11:37.284001 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-21 00:11:37.306472 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00
2026-01-21 00:11:37.421955 | controller | Collecting pytest>=3.10
2026-01-21 00:11:37.426280 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-21 00:11:37.447245 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 22.1 MB/s eta 0:00:00
2026-01-21 00:11:37.494784 | controller | Collecting iniconfig>=1.0.1
2026-01-21 00:11:37.498612 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-21 00:11:37.546147 | controller | Collecting packaging>=22
2026-01-21 00:11:37.549424 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-21 00:11:37.556242 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.7 MB/s eta 0:00:00
2026-01-21 00:11:37.604178 | controller | Collecting pluggy<2,>=1.5
2026-01-21 00:11:37.607605 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-21 00:11:37.660863 | controller | Collecting pygments>=2.7.2
2026-01-21 00:11:37.665889 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-21 00:11:37.692268 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 57.1 MB/s eta 0:00:00
2026-01-21 00:11:37.761867 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-21 00:11:38.831311 | 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-21 00:11:38.839926 | controller |
2026-01-21 00:11:38.927967 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:11:38.928016 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:11:39.128703 | controller | ok: Runtime: 0:00:25.635238
2026-01-21 00:11:39.135347 | 
2026-01-21 00:11:39.135446 | TASK [Update pip]
2026-01-21 00:11:39.667017 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-21 00:11:49.598465 | controller | Collecting pip
2026-01-21 00:12:01.793913 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-21 00:12:01.874680 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 23.4 MB/s eta 0:00:00
2026-01-21 00:12:01.940973 | controller | Installing collected packages: pip
2026-01-21 00:12:01.941071 | controller |   Attempting uninstall: pip
2026-01-21 00:12:01.943240 | controller |     Found existing installation: pip 22.2.2
2026-01-21 00:12:02.078259 | controller |     Uninstalling pip-22.2.2:
2026-01-21 00:12:02.093213 | controller |       Successfully uninstalled pip-22.2.2
2026-01-21 00:12:02.907777 | controller | Successfully installed pip-25.3
2026-01-21 00:12:03.208309 | controller | ok: Runtime: 0:00:23.601430
2026-01-21 00:12:03.222127 | 
2026-01-21 00:12:03.222299 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-21 00:12:03.448291 | controller | changed
2026-01-21 00:12:03.456553 | 
2026-01-21 00:12:03.456659 | TASK [Install ansible into virtualenv]
2026-01-21 00:12:03.947999 | controller | Processing ./src/github.com/ansible/ansible
2026-01-21 00:12:03.951640 | controller |   Installing build dependencies: started
2026-01-21 00:12:26.675844 | controller |   Installing build dependencies: finished with status 'done'
2026-01-21 00:12:26.676475 | controller |   Getting requirements to build wheel: started
2026-01-21 00:12:27.407921 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-21 00:12:27.409146 | controller |   Preparing metadata (pyproject.toml): started
2026-01-21 00:12:27.867521 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-21 00:12:27.872576 | 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-21 00:12:27.877053 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-21 00:12:28.015019 | controller | ERROR
2026-01-21 00:12:28.015255 | controller | {
2026-01-21 00:12:28.015296 | controller |   "delta": "0:00:24.264616",
2026-01-21 00:12:28.015321 | controller |   "end": "2026-01-21 00:12:27.934492",
2026-01-21 00:12:28.015344 | controller |   "msg": "non-zero return code",
2026-01-21 00:12:28.015380 | controller |   "rc": 1,
2026-01-21 00:12:28.015448 | controller |   "start": "2026-01-21 00:12:03.669876"
2026-01-21 00:12:28.015474 | controller | }
failure
2026-01-21 00:12:28.017469 | 
2026-01-21 00:12:28.017529 | PLAY RECAP
2026-01-21 00:12:28.017586 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-21 00:12:28.017617 | 
2026-01-21 00:12:28.187316 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:12:28.188289 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:12:28.823043 | 
2026-01-21 00:12:28.823227 | PLAY [all]
2026-01-21 00:12:28.848786 | 
2026-01-21 00:12:28.848972 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-21 00:12:29.118854 | controller | changed: non-zero return code
2026-01-21 00:12:29.125533 | 
2026-01-21 00:12:29.125683 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-21 00:12:29.152979 | controller | skipping: Conditional result was False
2026-01-21 00:12:29.160784 | 
2026-01-21 00:12:29.160917 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-21 00:12:29.184996 | 
2026-01-21 00:12:29.185167 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-21 00:12:29.206675 | 
2026-01-21 00:12:29.206878 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-21 00:12:29.221786 | controller | skipping: Conditional result was False
2026-01-21 00:12:29.229831 | 
2026-01-21 00:12:29.229979 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-21 00:12:29.251486 | 
2026-01-21 00:12:29.251659 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-21 00:12:29.265664 | controller | skipping: Conditional result was False
2026-01-21 00:12:29.272709 | 
2026-01-21 00:12:29.272812 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-21 00:12:29.287450 | controller | skipping: Conditional result was False
2026-01-21 00:12:29.294819 | 
2026-01-21 00:12:29.294918 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-21 00:12:29.309420 | controller | skipping: Conditional result was False
2026-01-21 00:12:29.336753 | 
2026-01-21 00:12:29.336856 | PLAY RECAP
2026-01-21 00:12:29.336897 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:12:29.336918 | 
2026-01-21 00:12:29.444195 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:12:29.445059 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-21 00:12:30.077557 | 
2026-01-21 00:12:30.077719 | PLAY [all:!appliance*]
2026-01-21 00:12:30.106826 | 
2026-01-21 00:12:30.106981 | TASK [unregister the node]
2026-01-21 00:12:30.644076 | controller | skipping: Conditional result was False
2026-01-21 00:12:30.650747 | 
2026-01-21 00:12:30.650849 | TASK [include_role : fetch-output]
2026-01-21 00:12:30.681558 | controller | ok
2026-01-21 00:12:30.702037 | 
2026-01-21 00:12:30.702147 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-21 00:12:30.747040 | controller | skipping: Conditional result was False
2026-01-21 00:12:30.753515 | 
2026-01-21 00:12:30.753592 | TASK [fetch-output : Set log path for single node]
2026-01-21 00:12:30.794305 | controller | ok
2026-01-21 00:12:30.800329 | 
2026-01-21 00:12:30.800414 | LOOP [fetch-output : Ensure local output dirs]
2026-01-21 00:12:31.249555 | controller -> localhost | ok: "/var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/logs"
2026-01-21 00:12:31.518205 | controller -> localhost | changed: "/var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/artifacts"
2026-01-21 00:12:31.785810 | controller -> localhost | changed: "/var/lib/zuul/builds/c8927f9a4dbe4884a456091086ee8eb8/work/docs"
2026-01-21 00:12:31.800701 | 
2026-01-21 00:12:31.800927 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-21 00:12:32.473552 | controller | changed:
2026-01-21 00:12:32.473979 | controller | .d..t...... ./
2026-01-21 00:12:32.474036 | controller | cd+++++++++ controller/
2026-01-21 00:12:32.474093 | controller | changed: All items complete
2026-01-21 00:12:32.474125 | 
2026-01-21 00:12:32.979516 | controller | changed: .d..t...... ./
2026-01-21 00:12:33.510056 | controller | changed: .d..t...... ./
2026-01-21 00:12:33.534363 | 
2026-01-21 00:12:33.534559 | TASK [include_role : fetch-output-openshift]
2026-01-21 00:12:33.562236 | controller | skipping: Conditional result was False
2026-01-21 00:12:33.578135 | 
2026-01-21 00:12:33.578370 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-21 00:12:33.627433 | controller | skipping: Conditional result was False
2026-01-21 00:12:33.641497 | controller | skipping: Conditional result was False
2026-01-21 00:12:33.688552 | 
2026-01-21 00:12:33.688834 | PLAY [localhost]
2026-01-21 00:12:33.706299 | 
2026-01-21 00:12:33.706473 | TASK [Run Zuul manifest role]
2026-01-21 00:12:33.731556 | localhost | ok
2026-01-21 00:12:33.779010 | 
2026-01-21 00:12:33.779208 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-21 00:12:34.198893 | localhost | changed
2026-01-21 00:12:34.205036 | 
2026-01-21 00:12:34.205145 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-21 00:12:34.235455 | localhost | ok
2026-01-21 00:12:34.245077 | 
2026-01-21 00:12:34.245148 | TASK [Set zuul-log-path fact]
2026-01-21 00:12:34.263377 | localhost | ok
2026-01-21 00:12:34.278531 | 
2026-01-21 00:12:34.278628 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:12:34.308194 | localhost | ok
2026-01-21 00:12:34.317672 | 
2026-01-21 00:12:34.317764 | LOOP [Run upload-logs-swift role]
2026-01-21 00:12:34.353325 | localhost | Output suppressed because no_log was given
2026-01-21 00:12:34.384868 | 
2026-01-21 00:12:34.384977 | TASK [Set zuul-log-path fact]
2026-01-21 00:12:34.430378 | localhost | skipping: Conditional result was False
2026-01-21 00:12:34.443809 | 
2026-01-21 00:12:34.443949 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-21 00:12:34.939271 | localhost -> localhost | ok: Runtime: 0:00:00.009367
2026-01-21 00:12:35.026720 | 
2026-01-21 00:12:35.026932 | TASK [upload-logs-swift : Upload logs to swift]