2026-01-21 00:22:45.630590 | Job console starting...
2026-01-21 00:22:45.640577 | Updating repositories
2026-01-21 00:22:45.742223 | Preparing job workspace
2026-01-21 00:22:50.186729 | Running Ansible setup...
2026-01-21 00:22:55.185579 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:22:55.917934 | 
2026-01-21 00:22:55.918348 | PLAY [localhost]
2026-01-21 00:22:55.929548 | 
2026-01-21 00:22:55.929683 | TASK [Gathering Facts]
2026-01-21 00:22:56.977652 | localhost | ok
2026-01-21 00:22:56.992208 | 
2026-01-21 00:22:56.992352 | TASK [Setup log path fact]
2026-01-21 00:22:57.011995 | localhost | ok
2026-01-21 00:22:57.026002 | 
2026-01-21 00:22:57.026165 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:22:57.065111 | localhost | ok
2026-01-21 00:22:57.074756 | 
2026-01-21 00:22:57.074908 | TASK [emit-job-header : Print job information]
2026-01-21 00:22:57.104625 | # Job Information
2026-01-21 00:22:57.104781 | Ansible Version: 2.15.12
2026-01-21 00:22:57.104811 | Job: ansible-test-sanity-docker-devel
2026-01-21 00:22:57.104833 | Pipeline: periodic
2026-01-21 00:22:57.104852 | Executor: ze01.softwarefactory-project.io
2026-01-21 00:22:57.104870 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-21 00:22:57.104891 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2d8/ansible/2d8bbd8b0248427c903058c8c00958fb/
2026-01-21 00:22:57.104910 | Event ID: 08cfdb9560914df89453f509f8798614
2026-01-21 00:22:57.108642 | 
2026-01-21 00:22:57.108733 | LOOP [emit-job-header : Print node information]
2026-01-21 00:22:57.211409 | localhost | ok:
2026-01-21 00:22:57.211704 | localhost | # Node Information
2026-01-21 00:22:57.211751 | localhost | Inventory Hostname: controller
2026-01-21 00:22:57.211776 | localhost | Hostname: np0005589754
2026-01-21 00:22:57.211797 | localhost | Username: zuul
2026-01-21 00:22:57.211825 | localhost | Distro: Fedora 37
2026-01-21 00:22:57.211847 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-21 00:22:57.211906 | localhost | Region: ca-ymq-1
2026-01-21 00:22:57.211925 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-21 00:22:57.211944 | localhost | Product Name: OpenStack Nova
2026-01-21 00:22:57.211962 | localhost | Interface IP: 162.253.55.206
2026-01-21 00:22:57.240336 | 
2026-01-21 00:22:57.240551 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-21 00:22:57.718911 | localhost -> localhost | changed
2026-01-21 00:22:57.726809 | 
2026-01-21 00:22:57.726951 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-21 00:22:58.736356 | localhost -> localhost | changed
2026-01-21 00:22:58.768435 | 
2026-01-21 00:22:58.768539 | PLAY [all:!appliance*]
2026-01-21 00:22:58.794967 | 
2026-01-21 00:22:58.795160 | TASK [include_role : start-zuul-console]
2026-01-21 00:22:58.819354 | controller | ok
2026-01-21 00:22:58.841588 | 
2026-01-21 00:22:58.841719 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-21 00:22:59.254221 | controller | ok
2026-01-21 00:22:59.270503 | 
2026-01-21 00:22:59.270596 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-21 00:23:00.221503 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-21 00:23:00.247872 | 
2026-01-21 00:23:00.248001 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-21 00:23:00.789505 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.799360 | 
2026-01-21 00:23:00.799515 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-21 00:23:00.825551 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.832315 | 
2026-01-21 00:23:00.832435 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-21 00:23:00.861078 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.868380 | 
2026-01-21 00:23:00.868519 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-21 00:23:00.883765 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.894352 | 
2026-01-21 00:23:00.894528 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-21 00:23:00.920862 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.928134 | 
2026-01-21 00:23:00.928252 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-21 00:23:00.953551 | controller | skipping: Conditional result was False
2026-01-21 00:23:00.970701 | 
2026-01-21 00:23:00.970848 | TASK [Disable Fedora Modular]
2026-01-21 00:23:01.209110 | controller | changed
2026-01-21 00:23:01.215919 | 
2026-01-21 00:23:01.216133 | TASK [Enable EPEL]
2026-01-21 00:23:01.241320 | controller | skipping: Conditional result was False
2026-01-21 00:23:01.248148 | 
2026-01-21 00:23:01.248238 | TASK [Register the RHEL node]
2026-01-21 00:23:01.788941 | 
2026-01-21 00:23:01.789129 | TASK [Show the subscription-manager status]
2026-01-21 00:23:02.355420 | controller | skipping: Conditional result was False
2026-01-21 00:23:02.362711 | 
2026-01-21 00:23:02.362848 | TASK [Enable EPEL on RHEL]
2026-01-21 00:23:02.896471 | controller | skipping: Conditional result was False
2026-01-21 00:23:02.905356 | 
2026-01-21 00:23:02.905510 | TASK [Install git and tox]
2026-01-21 00:24:26.302992 | controller | changed
2026-01-21 00:24:26.309698 | 
2026-01-21 00:24:26.309772 | TASK [include_role : prepare-workspace]
2026-01-21 00:24:26.330577 | controller | ok
2026-01-21 00:24:26.361514 | 
2026-01-21 00:24:26.361650 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-21 00:24:26.601165 | controller | ok
2026-01-21 00:24:26.616248 | 
2026-01-21 00:24:26.616372 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-21 00:24:39.863900 | controller | Output suppressed because no_log was given
2026-01-21 00:24:39.876774 | 
2026-01-21 00:24:39.876870 | TASK [include_role : prepare-workspace-openshift]
2026-01-21 00:24:39.901731 | controller | skipping: Conditional result was False
2026-01-21 00:24:39.924980 | 
2026-01-21 00:24:39.925114 | PLAY [all:!appliance]
2026-01-21 00:24:39.940938 | 
2026-01-21 00:24:39.941095 | TASK [Run add-build-sshkey role (RSA)]
2026-01-21 00:24:39.962006 | controller | ok
2026-01-21 00:24:39.981523 | 
2026-01-21 00:24:39.981645 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:24:40.234079 | controller -> localhost | ok
2026-01-21 00:24:40.241683 | 
2026-01-21 00:24:40.241797 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:24:40.262734 | controller | ok
2026-01-21 00:24:40.277920 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:24:40.284757 | 
2026-01-21 00:24:40.284867 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:24:40.740592 | controller -> localhost | Generating public/private rsa key pair.
2026-01-21 00:24:40.740825 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_rsa.
2026-01-21 00:24:40.740855 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_rsa.pub.
2026-01-21 00:24:40.740877 | controller -> localhost | The key fingerprint is:
2026-01-21 00:24:40.740896 | controller -> localhost | SHA256:6YCq/Q1Vpnu2CmSN5UCQ/cFujaMhXnqwixQ1ETb/MqI zuul-build-sshkey
2026-01-21 00:24:40.740915 | controller -> localhost | The key's randomart image is:
2026-01-21 00:24:40.740933 | controller -> localhost | +---[RSA 2048]----+
2026-01-21 00:24:40.740950 | controller -> localhost | |  .O+.           |
2026-01-21 00:24:40.740968 | controller -> localhost | |  o++ o          |
2026-01-21 00:24:40.740986 | controller -> localhost | |  . o+.+o        |
2026-01-21 00:24:40.741003 | controller -> localhost | | .o oBB+..       |
2026-01-21 00:24:40.741043 | controller -> localhost | | ..B=**oS        |
2026-01-21 00:24:40.741072 | controller -> localhost | | .=++.o+         |
2026-01-21 00:24:40.741095 | controller -> localhost | |.E.oo . +        |
2026-01-21 00:24:40.741116 | controller -> localhost | |.o.  + o .       |
2026-01-21 00:24:40.741135 | controller -> localhost | |. ... o..        |
2026-01-21 00:24:40.741157 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:24:40.741205 | controller -> localhost | ok: Runtime: 0:00:00.044443
2026-01-21 00:24:40.749947 | 
2026-01-21 00:24:40.750085 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:24:40.782192 | controller | ok
2026-01-21 00:24:40.796198 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:24:40.806942 | 
2026-01-21 00:24:40.807111 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:24:40.831205 | controller | skipping: Conditional result was False
2026-01-21 00:24:40.837940 | 
2026-01-21 00:24:40.838077 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:24:41.281560 | controller | changed
2026-01-21 00:24:41.288235 | 
2026-01-21 00:24:41.288386 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:24:41.517047 | controller | ok
2026-01-21 00:24:41.525513 | 
2026-01-21 00:24:41.525645 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:24:42.134404 | controller | changed
2026-01-21 00:24:42.141768 | 
2026-01-21 00:24:42.141877 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:24:42.745230 | controller | changed
2026-01-21 00:24:42.753918 | 
2026-01-21 00:24:42.754085 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:24:42.770505 | controller | skipping: Conditional result was False
2026-01-21 00:24:42.780177 | 
2026-01-21 00:24:42.780301 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:24:43.233878 | controller -> localhost | changed
2026-01-21 00:24:43.247509 | 
2026-01-21 00:24:43.247636 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:24:43.536509 | controller -> localhost | Identity added: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_rsa (zuul-build-sshkey)
2026-01-21 00:24:43.536791 | controller -> localhost | ok: Runtime: 0:00:00.008770
2026-01-21 00:24:43.545221 | 
2026-01-21 00:24:43.545470 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:24:43.899088 | controller | ok
2026-01-21 00:24:43.905701 | 
2026-01-21 00:24:43.905794 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:24:43.931403 | controller | skipping: Conditional result was False
2026-01-21 00:24:43.954224 | 
2026-01-21 00:24:43.954372 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-21 00:24:43.979923 | controller | ok
2026-01-21 00:24:43.999949 | 
2026-01-21 00:24:44.000100 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:24:44.240192 | controller -> localhost | ok
2026-01-21 00:24:44.250420 | 
2026-01-21 00:24:44.250586 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:24:44.279104 | controller | ok
2026-01-21 00:24:44.297436 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:24:44.308982 | 
2026-01-21 00:24:44.309228 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:24:44.591194 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-21 00:24:44.591514 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_ecdsa.
2026-01-21 00:24:44.591574 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_ecdsa.pub.
2026-01-21 00:24:44.591632 | controller -> localhost | The key fingerprint is:
2026-01-21 00:24:44.591666 | controller -> localhost | SHA256:Kj8okArEN6QQNX8RU0NrEKpO8SS8MVZJGX6r839JHVs zuul-build-sshkey
2026-01-21 00:24:44.591694 | controller -> localhost | The key's randomart image is:
2026-01-21 00:24:44.591721 | controller -> localhost | +---[ECDSA 521]---+
2026-01-21 00:24:44.591748 | controller -> localhost | |.oo.++*=+        |
2026-01-21 00:24:44.591774 | controller -> localhost | |.. *o. + o       |
2026-01-21 00:24:44.591799 | controller -> localhost | |o X = o o        |
2026-01-21 00:24:44.591824 | controller -> localhost | | = % o o    . E  |
2026-01-21 00:24:44.591849 | controller -> localhost | |..= o . S  . +   |
2026-01-21 00:24:44.591873 | controller -> localhost | |+o   . .  . o    |
2026-01-21 00:24:44.591897 | controller -> localhost | |o.. +..  . .     |
2026-01-21 00:24:44.591921 | controller -> localhost | |. . .=.   o      |
2026-01-21 00:24:44.591944 | controller -> localhost | |   .  oo..       |
2026-01-21 00:24:44.591968 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:24:44.592054 | controller -> localhost | ok: Runtime: 0:00:00.008811
2026-01-21 00:24:44.604111 | 
2026-01-21 00:24:44.604268 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:24:44.630846 | controller | ok
2026-01-21 00:24:44.643203 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:24:44.659684 | 
2026-01-21 00:24:44.659820 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:24:44.676294 | controller | skipping: Conditional result was False
2026-01-21 00:24:44.688780 | 
2026-01-21 00:24:44.689340 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:24:44.949966 | controller | changed
2026-01-21 00:24:44.959799 | 
2026-01-21 00:24:44.959948 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:24:45.177923 | controller | ok
2026-01-21 00:24:45.188423 | 
2026-01-21 00:24:45.188723 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:24:45.805676 | controller | changed
2026-01-21 00:24:45.816094 | 
2026-01-21 00:24:45.816250 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:24:46.390616 | controller | changed
2026-01-21 00:24:46.399188 | 
2026-01-21 00:24:46.399329 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:24:46.425785 | controller | skipping: Conditional result was False
2026-01-21 00:24:46.466935 | 
2026-01-21 00:24:46.467067 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:24:46.706368 | controller -> localhost | changed
2026-01-21 00:24:46.718754 | 
2026-01-21 00:24:46.718845 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:24:46.983434 | controller -> localhost | Identity added: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/2d8bbd8b0248427c903058c8c00958fb_id_ecdsa (zuul-build-sshkey)
2026-01-21 00:24:46.983621 | controller -> localhost | ok: Runtime: 0:00:00.007205
2026-01-21 00:24:46.990215 | 
2026-01-21 00:24:46.990301 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:29:51.661297 | controller | ok
2026-01-21 00:29:51.667165 | 
2026-01-21 00:29:51.667239 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:29:51.691706 | controller | skipping: Conditional result was False
2026-01-21 00:29:51.711536 | 
2026-01-21 00:29:51.711691 | TASK [include_role : remove-zuul-sshkey]
2026-01-21 00:29:51.736744 | controller | skipping: Conditional result was False
2026-01-21 00:29:51.745868 | 
2026-01-21 00:29:51.746077 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-21 00:29:51.962530 | controller | ok: "logs"
2026-01-21 00:29:51.962779 | controller | ok: All items complete
2026-01-21 00:29:51.962807 | 
2026-01-21 00:29:52.160082 | controller | ok: "artifacts"
2026-01-21 00:29:52.348211 | controller | ok: "docs"
2026-01-21 00:29:52.360446 | 
2026-01-21 00:29:52.360587 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-21 00:29:52.578052 | controller | changed: "logs"
2026-01-21 00:29:52.766039 | controller | changed: "artifacts"
2026-01-21 00:29:52.957989 | controller | changed: "docs"
2026-01-21 00:29:53.001876 | 
2026-01-21 00:29:53.001966 | PLAY RECAP
2026-01-21 00:29:53.002008 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-21 00:29:53.002052 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-21 00:29:53.002071 | 
2026-01-21 00:29:53.129391 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:29:53.130419 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:29:53.761225 | 
2026-01-21 00:29:53.761398 | PLAY [all]
2026-01-21 00:29:53.785698 | 
2026-01-21 00:29:53.785828 | TASK [Install binary dependencies]
2026-01-21 00:29:53.846442 | controller | ok
2026-01-21 00:29:53.867695 | 
2026-01-21 00:29:53.867837 | TASK [bindep : Include find tasks]
2026-01-21 00:29:53.898554 | controller | ok
2026-01-21 00:29:53.906169 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-21 00:29:53.913125 | 
2026-01-21 00:29:53.913205 | TASK [bindep : Look for bindep.txt]
2026-01-21 00:29:54.496261 | controller | ok
2026-01-21 00:29:54.505094 | 
2026-01-21 00:29:54.505236 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:29:54.520758 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.529926 | 
2026-01-21 00:29:54.530094 | TASK [bindep : Look for other-requirements.txt]
2026-01-21 00:29:54.738635 | controller | ok
2026-01-21 00:29:54.746894 | 
2026-01-21 00:29:54.746986 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:29:54.772665 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.780117 | 
2026-01-21 00:29:54.780289 | TASK [bindep : Look for bindep fallback file]
2026-01-21 00:29:54.805341 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.815416 | 
2026-01-21 00:29:54.815568 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:29:54.873239 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.880895 | 
2026-01-21 00:29:54.881054 | TASK [bindep : Include bindep tasks]
2026-01-21 00:29:54.925851 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.940966 | 
2026-01-21 00:29:54.941123 | TASK [bindep : Include install tasks]
2026-01-21 00:29:54.976824 | controller | skipping: Conditional result was False
2026-01-21 00:29:54.986505 | 
2026-01-21 00:29:54.986653 | LOOP [bindep : Include package tasks]
2026-01-21 00:29:55.053246 | 
2026-01-21 00:29:55.053413 | TASK [Run test-setup role]
2026-01-21 00:29:55.074111 | controller | ok
2026-01-21 00:29:55.091473 | 
2026-01-21 00:29:55.091570 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-21 00:29:55.294934 | controller | ok
2026-01-21 00:29:55.301310 | 
2026-01-21 00:29:55.301399 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-21 00:29:55.835260 | controller | skipping: Conditional result was False
2026-01-21 00:29:55.868637 | 
2026-01-21 00:29:55.868777 | PLAY RECAP
2026-01-21 00:29:55.868840 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:29:55.868874 | 
2026-01-21 00:29:55.999232 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:29:56.000139 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:29:56.615671 | 
2026-01-21 00:29:56.615800 | PLAY [controller]
2026-01-21 00:29:56.636841 | 
2026-01-21 00:29:56.636976 | TASK [Create the /root directory]
2026-01-21 00:29:57.223421 | controller | ok
2026-01-21 00:29:57.229590 | 
2026-01-21 00:29:57.229736 | TASK [Install glibc-langpack-en]
2026-01-21 00:30:01.071006 | controller | ok: Nothing to do
2026-01-21 00:30:01.081812 | 
2026-01-21 00:30:01.081970 | TASK [Ensure controller directory exists]
2026-01-21 00:30:01.293564 | controller | changed
2026-01-21 00:30:01.300628 | 
2026-01-21 00:30:01.301112 | TASK [Install container runtime]
2026-01-21 00:30:01.353705 | controller | ok
2026-01-21 00:30:01.394598 | 
2026-01-21 00:30:01.394757 | LOOP [ensure-podman : Find distribution installation]
2026-01-21 00:30:01.418974 | controller | ok: "/var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-21 00:30:01.431411 | controller | included: /var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-21 00:30:01.441528 | 
2026-01-21 00:30:01.441677 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-21 00:31:07.229725 | controller | changed
2026-01-21 00:31:07.240522 | 
2026-01-21 00:31:07.240670 | TASK [ensure-podman : Fetch podman version]
2026-01-21 00:31:07.771254 | controller | Client:       Podman Engine
2026-01-21 00:31:07.771367 | controller | Version:      4.6.2
2026-01-21 00:31:07.771413 | controller | API Version:  4.6.2
2026-01-21 00:31:07.771453 | controller | Go Version:   go1.19.12
2026-01-21 00:31:07.771504 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:31:07.771545 | controller | OS/Arch:      linux/amd64
2026-01-21 00:31:08.285820 | controller | ok: Runtime: 0:00:00.192274
2026-01-21 00:31:08.303637 | 
2026-01-21 00:31:08.303866 | TASK [ensure-podman : Print podman version installed]
2026-01-21 00:31:08.330789 | Podman version: Client:       Podman Engine
2026-01-21 00:31:08.331161 | Version:      4.6.2
2026-01-21 00:31:08.331209 | API Version:  4.6.2
2026-01-21 00:31:08.331244 | Go Version:   go1.19.12
2026-01-21 00:31:08.331271 | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:31:08.331302 | OS/Arch:      linux/amd64
2026-01-21 00:31:08.340864 | 
2026-01-21 00:31:08.340990 | TASK [ensure-podman : Validate podman engine]
2026-01-21 00:31:08.886699 | controller | skipping: Conditional result was False
2026-01-21 00:31:08.893377 | 
2026-01-21 00:31:08.893450 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-21 00:31:08.918262 | controller | skipping: Conditional result was False
2026-01-21 00:31:08.934716 | 
2026-01-21 00:31:08.934864 | TASK [Ensure python3.8 is present]
2026-01-21 00:31:08.951246 | controller | skipping: Conditional result was False
2026-01-21 00:31:08.960484 | 
2026-01-21 00:31:08.960617 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-21 00:31:08.984509 | controller | ok
2026-01-21 00:31:09.012587 | 
2026-01-21 00:31:09.012732 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-21 00:31:10.354249 | controller | ok: Nothing to do
2026-01-21 00:31:10.364183 | 
2026-01-21 00:31:10.364345 | TASK [our-ensure-python : Also install python3-devel]
2026-01-21 00:31:18.349662 | controller | changed
2026-01-21 00:31:18.374491 | 
2026-01-21 00:31:18.374613 | TASK [Run ensure-virtualenv role]
2026-01-21 00:31:18.395402 | controller | ok
2026-01-21 00:31:18.423127 | 
2026-01-21 00:31:18.423250 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-21 00:31:18.649378 | controller | /usr/bin/virtualenv
2026-01-21 00:31:18.960082 | controller | ok: Runtime: 0:00:00.007241
2026-01-21 00:31:18.966617 | 
2026-01-21 00:31:18.966723 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-21 00:31:18.994634 | controller | skipping: Conditional result was False
2026-01-21 00:31:18.994944 | controller | ok: All items complete
2026-01-21 00:31:18.994985 | 
2026-01-21 00:31:19.017044 | 
2026-01-21 00:31:19.017195 | TASK [Find the full path of the Python interpreter]
2026-01-21 00:31:19.235934 | controller | /usr/bin/python3
2026-01-21 00:31:19.555512 | controller | ok
2026-01-21 00:31:19.563636 | 
2026-01-21 00:31:19.563774 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-21 00:31:20.455567 | controller | created virtual environment CPython3.11.0.final.0-64 in 454ms
2026-01-21 00:31:20.475272 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-21 00:31:20.475303 | 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:31:20.475312 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-21 00:31:20.475325 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-21 00:31:20.602197 | controller | changed
2026-01-21 00:31:20.608880 | 
2026-01-21 00:31:20.609008 | TASK [Set selinux package]
2026-01-21 00:31:20.629790 | controller | ok
2026-01-21 00:31:20.635364 | 
2026-01-21 00:31:20.635457 | TASK [Set selinux package (Fedora)]
2026-01-21 00:31:20.667651 | controller | ok
2026-01-21 00:31:20.673957 | 
2026-01-21 00:31:20.674116 | TASK [Install selinux into virtualenv]
2026-01-21 00:31:21.907860 | controller | Collecting selinux-please-lie-to-me
2026-01-21 00:31:21.951664 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-21 00:31:22.250720 | controller | Collecting setuptools<50.0.0
2026-01-21 00:31:22.257106 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-21 00:31:22.294983 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.3 MB/s eta 0:00:00
2026-01-21 00:31:22.376346 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-21 00:31:22.376554 | controller |   Attempting uninstall: setuptools
2026-01-21 00:31:22.378938 | controller |     Found existing installation: setuptools 62.6.0
2026-01-21 00:31:22.437929 | controller |     Uninstalling setuptools-62.6.0:
2026-01-21 00:31:22.446192 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-21 00:31:22.848585 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-21 00:31:22.980012 | controller |
2026-01-21 00:31:23.070505 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:31:23.070539 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:31:23.217107 | controller | ok: Runtime: 0:00:02.199701
2026-01-21 00:31:23.223474 | 
2026-01-21 00:31:23.223578 | TASK [Install pytest-forked into virtualenv]
2026-01-21 00:31:23.863725 | controller | Collecting pytest-forked
2026-01-21 00:31:23.907474 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-21 00:31:23.953750 | controller | Collecting py
2026-01-21 00:31:23.958268 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-21 00:31:23.980844 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00
2026-01-21 00:31:24.085288 | controller | Collecting pytest>=3.10
2026-01-21 00:31:24.089876 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-21 00:31:24.106163 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.2 MB/s eta 0:00:00
2026-01-21 00:31:24.142316 | controller | Collecting iniconfig>=1.0.1
2026-01-21 00:31:24.145881 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-21 00:31:24.190388 | controller | Collecting packaging>=22
2026-01-21 00:31:24.193840 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-21 00:31:24.201351 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.9 MB/s eta 0:00:00
2026-01-21 00:31:24.233239 | controller | Collecting pluggy<2,>=1.5
2026-01-21 00:31:24.236256 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-21 00:31:24.284611 | controller | Collecting pygments>=2.7.2
2026-01-21 00:31:24.288260 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-21 00:31:24.306951 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 72.6 MB/s eta 0:00:00
2026-01-21 00:31:24.375550 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-21 00:31:25.464650 | 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:31:25.473164 | controller |
2026-01-21 00:31:25.540949 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:31:25.540991 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:31:25.785668 | controller | ok: Runtime: 0:00:02.110643
2026-01-21 00:31:25.795934 | 
2026-01-21 00:31:25.796072 | TASK [Update pip]
2026-01-21 00:31:26.297295 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-21 00:31:26.719531 | controller | Collecting pip
2026-01-21 00:31:26.756768 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-21 00:31:26.866720 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 16.6 MB/s eta 0:00:00
2026-01-21 00:31:26.929316 | controller | Installing collected packages: pip
2026-01-21 00:31:26.929528 | controller |   Attempting uninstall: pip
2026-01-21 00:31:26.931687 | controller |     Found existing installation: pip 22.2.2
2026-01-21 00:31:27.067404 | controller |     Uninstalling pip-22.2.2:
2026-01-21 00:31:27.082414 | controller |       Successfully uninstalled pip-22.2.2
2026-01-21 00:31:27.881591 | controller | Successfully installed pip-25.3
2026-01-21 00:31:28.340602 | controller | ok: Runtime: 0:00:01.949186
2026-01-21 00:31:28.348115 | 
2026-01-21 00:31:28.348247 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-21 00:31:28.556814 | controller | changed
2026-01-21 00:31:28.562904 | 
2026-01-21 00:31:28.562971 | TASK [Install ansible into virtualenv]
2026-01-21 00:31:29.029600 | controller | Processing ./src/github.com/ansible/ansible
2026-01-21 00:31:29.032857 | controller |   Installing build dependencies: started
2026-01-21 00:31:30.174201 | controller |   Installing build dependencies: finished with status 'done'
2026-01-21 00:31:30.174726 | controller |   Getting requirements to build wheel: started
2026-01-21 00:31:30.873271 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-21 00:31:30.874205 | controller |   Preparing metadata (pyproject.toml): started
2026-01-21 00:31:31.325192 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-21 00:31:31.327196 | 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:31:31.329719 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-21 00:31:31.609498 | controller | ERROR
2026-01-21 00:31:31.609669 | controller | {
2026-01-21 00:31:31.609709 | controller |   "delta": "0:00:02.628573",
2026-01-21 00:31:31.609735 | controller |   "end": "2026-01-21 00:31:31.386009",
2026-01-21 00:31:31.609804 | controller |   "msg": "non-zero return code",
2026-01-21 00:31:31.609849 | controller |   "rc": 1,
2026-01-21 00:31:31.609890 | controller |   "start": "2026-01-21 00:31:28.757436"
2026-01-21 00:31:31.609917 | controller | }
failure
2026-01-21 00:31:31.612212 | 
2026-01-21 00:31:31.612349 | PLAY RECAP
2026-01-21 00:31:31.612415 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-21 00:31:31.612439 | 
2026-01-21 00:31:31.753636 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:31:31.754965 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:31:32.381164 | 
2026-01-21 00:31:32.381300 | PLAY [all]
2026-01-21 00:31:32.416269 | 
2026-01-21 00:31:32.416434 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-21 00:31:32.790128 | controller | changed: non-zero return code
2026-01-21 00:31:32.797963 | 
2026-01-21 00:31:32.798072 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-21 00:31:32.814418 | controller | skipping: Conditional result was False
2026-01-21 00:31:32.821301 | 
2026-01-21 00:31:32.821386 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-21 00:31:32.842849 | 
2026-01-21 00:31:32.843041 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-21 00:31:32.873683 | 
2026-01-21 00:31:32.873872 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-21 00:31:32.887823 | controller | skipping: Conditional result was False
2026-01-21 00:31:32.895510 | 
2026-01-21 00:31:32.895585 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-21 00:31:32.917227 | 
2026-01-21 00:31:32.917390 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-21 00:31:32.931466 | controller | skipping: Conditional result was False
2026-01-21 00:31:32.938273 | 
2026-01-21 00:31:32.938355 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-21 00:31:32.952276 | controller | skipping: Conditional result was False
2026-01-21 00:31:32.959419 | 
2026-01-21 00:31:32.959514 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-21 00:31:32.973932 | controller | skipping: Conditional result was False
2026-01-21 00:31:33.003622 | 
2026-01-21 00:31:33.003731 | PLAY RECAP
2026-01-21 00:31:33.003775 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:31:33.003795 | 
2026-01-21 00:31:33.122030 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:31:33.123091 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-21 00:31:33.704430 | 
2026-01-21 00:31:33.704575 | PLAY [all:!appliance*]
2026-01-21 00:31:33.728414 | 
2026-01-21 00:31:33.728582 | TASK [unregister the node]
2026-01-21 00:31:34.263927 | controller | skipping: Conditional result was False
2026-01-21 00:31:34.277387 | 
2026-01-21 00:31:34.277616 | TASK [include_role : fetch-output]
2026-01-21 00:31:34.312001 | controller | ok
2026-01-21 00:31:34.346451 | 
2026-01-21 00:31:34.346664 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-21 00:31:34.402293 | controller | skipping: Conditional result was False
2026-01-21 00:31:34.409223 | 
2026-01-21 00:31:34.409357 | TASK [fetch-output : Set log path for single node]
2026-01-21 00:31:34.459732 | controller | ok
2026-01-21 00:31:34.465336 | 
2026-01-21 00:31:34.465455 | LOOP [fetch-output : Ensure local output dirs]
2026-01-21 00:31:34.921837 | controller -> localhost | ok: "/var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/logs"
2026-01-21 00:31:35.183354 | controller -> localhost | changed: "/var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/artifacts"
2026-01-21 00:31:35.416493 | controller -> localhost | changed: "/var/lib/zuul/builds/2d8bbd8b0248427c903058c8c00958fb/work/docs"
2026-01-21 00:31:35.429186 | 
2026-01-21 00:31:35.429281 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-21 00:31:36.110556 | controller | changed:
2026-01-21 00:31:36.110918 | controller | .d..t...... ./
2026-01-21 00:31:36.110997 | controller | cd+++++++++ controller/
2026-01-21 00:31:36.111115 | controller | changed: All items complete
2026-01-21 00:31:36.111162 | 
2026-01-21 00:31:36.630171 | controller | changed: .d..t...... ./
2026-01-21 00:31:37.101150 | controller | changed: .d..t...... ./
2026-01-21 00:31:37.128479 | 
2026-01-21 00:31:37.128641 | TASK [include_role : fetch-output-openshift]
2026-01-21 00:31:37.144256 | controller | skipping: Conditional result was False
2026-01-21 00:31:37.154386 | 
2026-01-21 00:31:37.154524 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-21 00:31:37.183398 | controller | skipping: Conditional result was False
2026-01-21 00:31:37.197380 | controller | skipping: Conditional result was False
2026-01-21 00:31:37.231192 | 
2026-01-21 00:31:37.231297 | PLAY [localhost]
2026-01-21 00:31:37.245708 | 
2026-01-21 00:31:37.245833 | TASK [Run Zuul manifest role]
2026-01-21 00:31:37.266091 | localhost | ok
2026-01-21 00:31:37.287893 | 
2026-01-21 00:31:37.288075 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-21 00:31:37.697677 | localhost | changed
2026-01-21 00:31:37.703355 | 
2026-01-21 00:31:37.703508 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-21 00:31:37.741125 | localhost | ok
2026-01-21 00:31:37.752101 | 
2026-01-21 00:31:37.752231 | TASK [Set zuul-log-path fact]
2026-01-21 00:31:37.773186 | localhost | ok
2026-01-21 00:31:37.794119 | 
2026-01-21 00:31:37.794262 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:31:37.825652 | localhost | ok
2026-01-21 00:31:37.837527 | 
2026-01-21 00:31:37.837638 | LOOP [Run upload-logs-swift role]
2026-01-21 00:31:37.873248 | localhost | Output suppressed because no_log was given
2026-01-21 00:31:37.912385 | 
2026-01-21 00:31:37.912534 | TASK [Set zuul-log-path fact]
2026-01-21 00:31:37.938255 | localhost | skipping: Conditional result was False
2026-01-21 00:31:37.946778 | 
2026-01-21 00:31:37.946900 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-21 00:31:38.361376 | localhost -> localhost | ok: Runtime: 0:00:00.006134
2026-01-21 00:31:38.401640 | 
2026-01-21 00:31:38.401782 | TASK [upload-logs-swift : Upload logs to swift]