2026-02-06 00:34:33.036978 | Job console starting...
2026-02-06 00:34:33.053256 | Updating repositories
2026-02-06 00:34:33.260337 | Preparing job workspace
2026-02-06 00:34:37.779371 | Running Ansible setup...
2026-02-06 00:34:42.764036 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-06 00:34:43.458502 | 
2026-02-06 00:34:43.458729 | PLAY [localhost]
2026-02-06 00:34:43.469136 | 
2026-02-06 00:34:43.469251 | TASK [Gathering Facts]
2026-02-06 00:34:44.627984 | localhost | ok
2026-02-06 00:34:44.654286 | 
2026-02-06 00:34:44.654771 | TASK [Setup log path fact]
2026-02-06 00:34:44.675309 | localhost | ok
2026-02-06 00:34:44.693230 | 
2026-02-06 00:34:44.693552 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-06 00:34:44.723694 | localhost | ok
2026-02-06 00:34:44.735165 | 
2026-02-06 00:34:44.735279 | TASK [emit-job-header : Print job information]
2026-02-06 00:34:44.775909 | # Job Information
2026-02-06 00:34:44.776135 | Ansible Version: 2.15.12
2026-02-06 00:34:44.776171 | Job: ansible-test-sanity-docker-devel
2026-02-06 00:34:44.776192 | Pipeline: periodic
2026-02-06 00:34:44.776211 | Executor: ze04.softwarefactory-project.io
2026-02-06 00:34:44.776230 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-06 00:34:44.776251 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/852/ansible/852827efe8714a2e9b8db084c740b53c/
2026-02-06 00:34:44.776271 | Event ID: ebfa20167ca74e4389cc224acfe9a040
2026-02-06 00:34:44.780637 | 
2026-02-06 00:34:44.780737 | LOOP [emit-job-header : Print node information]
2026-02-06 00:34:44.904138 | localhost | ok:
2026-02-06 00:34:44.904537 | localhost | # Node Information
2026-02-06 00:34:44.904581 | localhost | Inventory Hostname: controller
2026-02-06 00:34:44.904611 | localhost | Hostname: np0005610385
2026-02-06 00:34:44.904639 | localhost | Username: zuul
2026-02-06 00:34:44.904709 | localhost | Distro: Fedora 37
2026-02-06 00:34:44.904745 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-06 00:34:44.904770 | localhost | Region: ca-ymq-1
2026-02-06 00:34:44.904795 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-06 00:34:44.904819 | localhost | Product Name: OpenStack Nova
2026-02-06 00:34:44.904865 | localhost | Interface IP: 199.204.45.113
2026-02-06 00:34:44.917462 | 
2026-02-06 00:34:44.917657 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-06 00:34:45.362897 | localhost -> localhost | changed
2026-02-06 00:34:45.369432 | 
2026-02-06 00:34:45.369512 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-06 00:34:46.303410 | localhost -> localhost | changed
2026-02-06 00:34:46.361949 | 
2026-02-06 00:34:46.362221 | PLAY [all:!appliance*]
2026-02-06 00:34:46.386164 | 
2026-02-06 00:34:46.386312 | TASK [include_role : start-zuul-console]
2026-02-06 00:34:46.415014 | controller | ok
2026-02-06 00:34:46.438319 | 
2026-02-06 00:34:46.438533 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-06 00:34:46.865884 | controller | ok
2026-02-06 00:34:46.893308 | 
2026-02-06 00:34:46.893463 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-06 00:35:24.878354 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-06 00:35:24.898558 | 
2026-02-06 00:35:24.898863 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-06 00:35:25.490638 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.502000 | 
2026-02-06 00:35:25.502129 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-06 00:35:25.532464 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.550414 | 
2026-02-06 00:35:25.550601 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-06 00:35:25.578835 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.588648 | 
2026-02-06 00:35:25.588782 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-06 00:35:25.615019 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.624605 | 
2026-02-06 00:35:25.624837 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-06 00:35:25.661565 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.670923 | 
2026-02-06 00:35:25.671026 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-06 00:35:25.696327 | controller | skipping: Conditional result was False
2026-02-06 00:35:25.715182 | 
2026-02-06 00:35:25.715305 | TASK [Disable Fedora Modular]
2026-02-06 00:35:25.989294 | controller | changed
2026-02-06 00:35:25.998878 | 
2026-02-06 00:35:25.999002 | TASK [Enable EPEL]
2026-02-06 00:35:26.024488 | controller | skipping: Conditional result was False
2026-02-06 00:35:26.035859 | 
2026-02-06 00:35:26.036075 | TASK [Register the RHEL node]
2026-02-06 00:35:26.594322 | 
2026-02-06 00:35:26.594639 | TASK [Show the subscription-manager status]
2026-02-06 00:35:27.156026 | controller | skipping: Conditional result was False
2026-02-06 00:35:27.162922 | 
2026-02-06 00:35:27.162994 | TASK [Enable EPEL on RHEL]
2026-02-06 00:35:27.695071 | controller | skipping: Conditional result was False
2026-02-06 00:35:27.711365 | 
2026-02-06 00:35:27.711587 | TASK [Install git and tox]
2026-02-06 00:36:28.904100 | controller | changed
2026-02-06 00:36:28.920727 | 
2026-02-06 00:36:28.920909 | TASK [include_role : prepare-workspace]
2026-02-06 00:36:28.963013 | controller | ok
2026-02-06 00:36:28.999140 | 
2026-02-06 00:36:28.999337 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-06 00:36:29.259207 | controller | ok
2026-02-06 00:36:29.269803 | 
2026-02-06 00:36:29.269985 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-06 00:36:41.996774 | controller | Output suppressed because no_log was given
2026-02-06 00:36:42.008395 | 
2026-02-06 00:36:42.008479 | TASK [include_role : prepare-workspace-openshift]
2026-02-06 00:36:42.027840 | controller | skipping: Conditional result was False
2026-02-06 00:36:42.106756 | 
2026-02-06 00:36:42.106867 | PLAY [all:!appliance]
2026-02-06 00:36:42.124452 | 
2026-02-06 00:36:42.124575 | TASK [Run add-build-sshkey role (RSA)]
2026-02-06 00:36:42.155833 | controller | ok
2026-02-06 00:36:42.172185 | 
2026-02-06 00:36:42.172346 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-06 00:36:42.443204 | controller -> localhost | ok
2026-02-06 00:36:42.457444 | 
2026-02-06 00:36:42.457612 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-06 00:36:42.496373 | controller | ok
2026-02-06 00:36:42.526406 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-06 00:36:42.536078 | 
2026-02-06 00:36:42.536215 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-06 00:36:43.052891 | controller -> localhost | Generating public/private rsa key pair.
2026-02-06 00:36:43.053215 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_rsa.
2026-02-06 00:36:43.053256 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_rsa.pub.
2026-02-06 00:36:43.053286 | controller -> localhost | The key fingerprint is:
2026-02-06 00:36:43.053313 | controller -> localhost | SHA256:K073MW7AsgQ+SlIzs6z17QwQZD0DCVWqloVZBOThA68 zuul-build-sshkey
2026-02-06 00:36:43.053341 | controller -> localhost | The key's randomart image is:
2026-02-06 00:36:43.053376 | controller -> localhost | +---[RSA 2048]----+
2026-02-06 00:36:43.053410 | controller -> localhost | |+*BB.            |
2026-02-06 00:36:43.053438 | controller -> localhost | |++*.+            |
2026-02-06 00:36:43.053464 | controller -> localhost | | *+. o           |
2026-02-06 00:36:43.053490 | controller -> localhost | | oO..            |
2026-02-06 00:36:43.053516 | controller -> localhost | |E=.* . .S        |
2026-02-06 00:36:43.053556 | controller -> localhost | |o =.o o o.       |
2026-02-06 00:36:43.053590 | controller -> localhost | | = o.+ooo.o      |
2026-02-06 00:36:43.053617 | controller -> localhost | |. . .=oo o.o     |
2026-02-06 00:36:43.053643 | controller -> localhost | |     .+  .o      |
2026-02-06 00:36:43.053673 | controller -> localhost | +----[SHA256]-----+
2026-02-06 00:36:43.054008 | controller -> localhost | ok: Runtime: 0:00:00.115133
2026-02-06 00:36:43.063901 | 
2026-02-06 00:36:43.064101 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-06 00:36:43.099139 | controller | ok
2026-02-06 00:36:43.114594 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-06 00:36:43.129584 | 
2026-02-06 00:36:43.129673 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-06 00:36:43.165651 | controller | skipping: Conditional result was False
2026-02-06 00:36:43.176148 | 
2026-02-06 00:36:43.176268 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-06 00:36:43.665512 | controller | changed
2026-02-06 00:36:43.679037 | 
2026-02-06 00:36:43.679227 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-06 00:36:43.935911 | controller | ok
2026-02-06 00:36:43.947945 | 
2026-02-06 00:36:43.948152 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-06 00:36:44.616295 | controller | changed
2026-02-06 00:36:44.629189 | 
2026-02-06 00:36:44.629397 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-06 00:36:45.286333 | controller | changed
2026-02-06 00:36:45.295590 | 
2026-02-06 00:36:45.295754 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-06 00:36:45.332420 | controller | skipping: Conditional result was False
2026-02-06 00:36:45.340575 | 
2026-02-06 00:36:45.340861 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-06 00:36:45.773490 | controller -> localhost | changed
2026-02-06 00:36:45.786464 | 
2026-02-06 00:36:45.786765 | TASK [add-build-sshkey : Add back temp key]
2026-02-06 00:36:46.129862 | controller -> localhost | Identity added: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_rsa (zuul-build-sshkey)
2026-02-06 00:36:46.130364 | controller -> localhost | ok: Runtime: 0:00:00.015978
2026-02-06 00:36:46.145378 | 
2026-02-06 00:36:46.145521 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-06 00:36:46.536049 | controller | ok
2026-02-06 00:36:46.551539 | 
2026-02-06 00:36:46.551857 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-06 00:36:46.579012 | controller | skipping: Conditional result was False
2026-02-06 00:36:46.606222 | 
2026-02-06 00:36:46.606392 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-06 00:36:46.642015 | controller | ok
2026-02-06 00:36:46.666099 | 
2026-02-06 00:36:46.666198 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-06 00:36:46.938009 | controller -> localhost | ok
2026-02-06 00:36:46.956313 | 
2026-02-06 00:36:46.956560 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-06 00:36:47.005809 | controller | ok
2026-02-06 00:36:47.029367 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-06 00:36:47.041373 | 
2026-02-06 00:36:47.041547 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-06 00:36:47.437999 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-06 00:36:47.438382 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_ecdsa.
2026-02-06 00:36:47.438444 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_ecdsa.pub.
2026-02-06 00:36:47.438506 | controller -> localhost | The key fingerprint is:
2026-02-06 00:36:47.438552 | controller -> localhost | SHA256:+gM5yFne5XcZWFINN153H6MWO/ni7Ny2f8/Lfhc2VNg zuul-build-sshkey
2026-02-06 00:36:47.438595 | controller -> localhost | The key's randomart image is:
2026-02-06 00:36:47.438637 | controller -> localhost | +---[ECDSA 521]---+
2026-02-06 00:36:47.438707 | controller -> localhost | |             ooO=|
2026-02-06 00:36:47.438757 | controller -> localhost | |            . O.E|
2026-02-06 00:36:47.438797 | controller -> localhost | |             X .o|
2026-02-06 00:36:47.438836 | controller -> localhost | |      .   . o +. |
2026-02-06 00:36:47.438874 | controller -> localhost | |   . = oSo   ..+ |
2026-02-06 00:36:47.438913 | controller -> localhost | |    + =.. . + ++ |
2026-02-06 00:36:47.438951 | controller -> localhost | |      .o   . +. o|
2026-02-06 00:36:47.438990 | controller -> localhost | |       ..   o oo+|
2026-02-06 00:36:47.439029 | controller -> localhost | |        ..   oo*%|
2026-02-06 00:36:47.439067 | controller -> localhost | +----[SHA256]-----+
2026-02-06 00:36:47.439158 | controller -> localhost | ok: Runtime: 0:00:00.014626
2026-02-06 00:36:47.454538 | 
2026-02-06 00:36:47.454748 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-06 00:36:47.485029 | controller | ok
2026-02-06 00:36:47.502028 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-06 00:36:47.515804 | 
2026-02-06 00:36:47.515942 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-06 00:36:47.531345 | controller | skipping: Conditional result was False
2026-02-06 00:36:47.541448 | 
2026-02-06 00:36:47.541636 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-06 00:36:47.817759 | controller | changed
2026-02-06 00:36:47.831316 | 
2026-02-06 00:36:47.831457 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-06 00:36:48.101049 | controller | ok
2026-02-06 00:36:48.115736 | 
2026-02-06 00:36:48.115882 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-06 00:36:48.782819 | controller | changed
2026-02-06 00:36:48.797033 | 
2026-02-06 00:36:48.797247 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-06 00:36:49.465278 | controller | changed
2026-02-06 00:36:49.478605 | 
2026-02-06 00:36:49.478795 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-06 00:36:49.519370 | controller | skipping: Conditional result was False
2026-02-06 00:36:49.535421 | 
2026-02-06 00:36:49.535586 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-06 00:36:49.832767 | controller -> localhost | changed
2026-02-06 00:36:49.895274 | 
2026-02-06 00:36:49.895418 | TASK [add-build-sshkey : Add back temp key]
2026-02-06 00:36:50.247202 | controller -> localhost | Identity added: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/852827efe8714a2e9b8db084c740b53c_id_ecdsa (zuul-build-sshkey)
2026-02-06 00:36:50.247607 | controller -> localhost | ok: Runtime: 0:00:00.016019
2026-02-06 00:36:50.257967 | 
2026-02-06 00:36:50.258059 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-06 00:36:50.486257 | controller | ok
2026-02-06 00:36:50.495110 | 
2026-02-06 00:36:50.495219 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-06 00:36:50.520543 | controller | skipping: Conditional result was False
2026-02-06 00:36:50.542296 | 
2026-02-06 00:36:50.542487 | TASK [include_role : remove-zuul-sshkey]
2026-02-06 00:36:50.568867 | controller | skipping: Conditional result was False
2026-02-06 00:36:50.579585 | 
2026-02-06 00:36:50.579785 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-06 00:36:50.828367 | controller | ok: "logs"
2026-02-06 00:36:50.828731 | controller | ok: All items complete
2026-02-06 00:36:50.828787 | 
2026-02-06 00:36:51.030920 | controller | ok: "artifacts"
2026-02-06 00:36:51.226312 | controller | ok: "docs"
2026-02-06 00:36:51.255479 | 
2026-02-06 00:36:51.255985 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-06 00:36:51.509718 | controller | changed: "logs"
2026-02-06 00:36:51.715156 | controller | changed: "artifacts"
2026-02-06 00:36:51.918226 | controller | changed: "docs"
2026-02-06 00:36:51.984372 | 
2026-02-06 00:36:51.984517 | PLAY RECAP
2026-02-06 00:36:51.984577 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-06 00:36:51.984613 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-06 00:36:51.984638 | 
2026-02-06 00:36:52.171052 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-06 00:36:52.173043 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-06 00:36:52.836051 | 
2026-02-06 00:36:52.836352 | PLAY [all]
2026-02-06 00:36:52.867905 | 
2026-02-06 00:36:52.868101 | TASK [Install binary dependencies]
2026-02-06 00:36:52.932552 | controller | ok
2026-02-06 00:36:52.964261 | 
2026-02-06 00:36:52.964488 | TASK [bindep : Include find tasks]
2026-02-06 00:36:53.005784 | controller | ok
2026-02-06 00:36:53.014632 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-06 00:36:53.021718 | 
2026-02-06 00:36:53.021792 | TASK [bindep : Look for bindep.txt]
2026-02-06 00:36:53.376040 | controller | ok
2026-02-06 00:36:53.389352 | 
2026-02-06 00:36:53.389501 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:36:53.417130 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.431390 | 
2026-02-06 00:36:53.431542 | TASK [bindep : Look for other-requirements.txt]
2026-02-06 00:36:53.665358 | controller | ok
2026-02-06 00:36:53.678479 | 
2026-02-06 00:36:53.678648 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:36:53.716822 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.731002 | 
2026-02-06 00:36:53.731157 | TASK [bindep : Look for bindep fallback file]
2026-02-06 00:36:53.772959 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.789498 | 
2026-02-06 00:36:53.789669 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:36:53.817416 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.831623 | 
2026-02-06 00:36:53.831843 | TASK [bindep : Include bindep tasks]
2026-02-06 00:36:53.869649 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.883972 | 
2026-02-06 00:36:53.884162 | TASK [bindep : Include install tasks]
2026-02-06 00:36:53.921888 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.936943 | 
2026-02-06 00:36:53.937102 | LOOP [bindep : Include package tasks]
2026-02-06 00:36:54.020153 | 
2026-02-06 00:36:54.020427 | TASK [Run test-setup role]
2026-02-06 00:36:54.052322 | controller | ok
2026-02-06 00:36:54.082059 | 
2026-02-06 00:36:54.082203 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-06 00:36:54.292731 | controller | ok
2026-02-06 00:36:54.306436 | 
2026-02-06 00:36:54.306605 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-06 00:36:54.859946 | controller | skipping: Conditional result was False
2026-02-06 00:36:54.915796 | 
2026-02-06 00:36:54.915930 | PLAY RECAP
2026-02-06 00:36:54.915988 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-06 00:36:54.916015 | 
2026-02-06 00:36:55.036937 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-06 00:36:55.038846 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-06 00:36:55.634883 | 
2026-02-06 00:36:55.635018 | PLAY [controller]
2026-02-06 00:36:55.655582 | 
2026-02-06 00:36:55.655704 | TASK [Create the /root directory]
2026-02-06 00:36:56.075900 | controller | ok
2026-02-06 00:36:56.090748 | 
2026-02-06 00:36:56.090926 | TASK [Install glibc-langpack-en]
2026-02-06 00:37:00.066162 | controller | ok: Nothing to do
2026-02-06 00:37:00.081296 | 
2026-02-06 00:37:00.081498 | TASK [Ensure controller directory exists]
2026-02-06 00:37:00.295924 | controller | changed
2026-02-06 00:37:00.310111 | 
2026-02-06 00:37:00.310312 | TASK [Install container runtime]
2026-02-06 00:37:00.394531 | controller | ok
2026-02-06 00:37:00.448252 | 
2026-02-06 00:37:00.448441 | LOOP [ensure-podman : Find distribution installation]
2026-02-06 00:37:00.484792 | controller | ok: "/var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-06 00:37:00.499346 | controller | included: /var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-06 00:37:00.510357 | 
2026-02-06 00:37:00.510456 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-06 00:38:09.230178 | controller | changed
2026-02-06 00:38:09.244787 | 
2026-02-06 00:38:09.244939 | TASK [ensure-podman : Fetch podman version]
2026-02-06 00:38:09.843839 | controller | Client:       Podman Engine
2026-02-06 00:38:09.873251 | controller | Version:      4.6.2
2026-02-06 00:38:09.873290 | controller | API Version:  4.6.2
2026-02-06 00:38:09.873305 | controller | Go Version:   go1.19.12
2026-02-06 00:38:09.873334 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-06 00:38:09.873347 | controller | OS/Arch:      linux/amd64
2026-02-06 00:38:10.300160 | controller | ok: Runtime: 0:00:00.187311
2026-02-06 00:38:10.317030 | 
2026-02-06 00:38:10.317187 | TASK [ensure-podman : Print podman version installed]
2026-02-06 00:38:10.361527 | Podman version: Client:       Podman Engine
2026-02-06 00:38:10.361889 | Version:      4.6.2
2026-02-06 00:38:10.361961 | API Version:  4.6.2
2026-02-06 00:38:10.362010 | Go Version:   go1.19.12
2026-02-06 00:38:10.362054 | Built:        Mon Aug 28 19:38:31 2023
2026-02-06 00:38:10.362099 | OS/Arch:      linux/amd64
2026-02-06 00:38:10.376300 | 
2026-02-06 00:38:10.376446 | TASK [ensure-podman : Validate podman engine]
2026-02-06 00:38:10.927379 | controller | skipping: Conditional result was False
2026-02-06 00:38:10.943664 | 
2026-02-06 00:38:10.943871 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-06 00:38:10.972150 | controller | skipping: Conditional result was False
2026-02-06 00:38:11.001544 | 
2026-02-06 00:38:11.001802 | TASK [Ensure python3.8 is present]
2026-02-06 00:38:11.029327 | controller | skipping: Conditional result was False
2026-02-06 00:38:11.039787 | 
2026-02-06 00:38:11.039882 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-06 00:38:11.065962 | controller | ok
2026-02-06 00:38:11.099861 | 
2026-02-06 00:38:11.100161 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-06 00:38:12.485224 | controller | ok: Nothing to do
2026-02-06 00:38:12.494271 | 
2026-02-06 00:38:12.494360 | TASK [our-ensure-python : Also install python3-devel]
2026-02-06 00:38:21.632073 | controller | changed
2026-02-06 00:38:21.660670 | 
2026-02-06 00:38:21.661012 | TASK [Run ensure-virtualenv role]
2026-02-06 00:38:21.690010 | controller | ok
2026-02-06 00:38:21.723512 | 
2026-02-06 00:38:21.723722 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-06 00:38:22.014088 | controller | /usr/bin/virtualenv
2026-02-06 00:38:22.316515 | controller | ok: Runtime: 0:00:00.004505
2026-02-06 00:38:22.326659 | 
2026-02-06 00:38:22.326878 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-06 00:38:22.365166 | controller | skipping: Conditional result was False
2026-02-06 00:38:22.365714 | controller | ok: All items complete
2026-02-06 00:38:22.365798 | 
2026-02-06 00:38:22.396035 | 
2026-02-06 00:38:22.396265 | TASK [Find the full path of the Python interpreter]
2026-02-06 00:38:22.643691 | controller | /usr/bin/python3
2026-02-06 00:38:22.950408 | controller | ok
2026-02-06 00:38:22.957249 | 
2026-02-06 00:38:22.957375 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-06 00:38:23.723840 | controller | created virtual environment CPython3.11.0.final.0-64 in 439ms
2026-02-06 00:38:23.746556 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-06 00:38:23.746591 | 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-02-06 00:38:23.746601 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-06 00:38:23.746613 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-06 00:38:23.998606 | controller | changed
2026-02-06 00:38:24.024576 | 
2026-02-06 00:38:24.024748 | TASK [Set selinux package]
2026-02-06 00:38:24.057148 | controller | ok
2026-02-06 00:38:24.063065 | 
2026-02-06 00:38:24.063134 | TASK [Set selinux package (Fedora)]
2026-02-06 00:38:24.105064 | controller | ok
2026-02-06 00:38:24.110798 | 
2026-02-06 00:38:24.110893 | TASK [Install selinux into virtualenv]
2026-02-06 00:38:49.578127 | controller | Collecting selinux-please-lie-to-me
2026-02-06 00:39:01.838261 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-06 00:39:02.146717 | controller | Collecting setuptools<50.0.0
2026-02-06 00:39:02.151341 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-06 00:39:02.187705 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.3 MB/s eta 0:00:00
2026-02-06 00:39:02.265225 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-06 00:39:02.265441 | controller |   Attempting uninstall: setuptools
2026-02-06 00:39:02.267823 | controller |     Found existing installation: setuptools 62.6.0
2026-02-06 00:39:02.327146 | controller |     Uninstalling setuptools-62.6.0:
2026-02-06 00:39:02.335007 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-06 00:39:02.708147 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-06 00:39:14.212845 | controller |
2026-02-06 00:39:14.301291 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-06 00:39:14.301341 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-06 00:39:14.670135 | controller | ok: Runtime: 0:00:49.981889
2026-02-06 00:39:14.684629 | 
2026-02-06 00:39:14.684814 | TASK [Install pytest-forked into virtualenv]
2026-02-06 00:39:26.455538 | controller | Collecting pytest-forked
2026-02-06 00:39:38.693384 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-06 00:39:39.399398 | controller | Collecting py
2026-02-06 00:39:39.405209 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-06 00:39:39.423287 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.6 MB/s eta 0:00:00
2026-02-06 00:39:39.569200 | controller | Collecting pytest>=3.10
2026-02-06 00:39:39.595039 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-06 00:39:39.610194 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.5 MB/s eta 0:00:00
2026-02-06 00:39:39.647773 | controller | Collecting iniconfig>=1.0.1
2026-02-06 00:39:39.651333 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-06 00:39:39.692018 | controller | Collecting packaging>=22
2026-02-06 00:39:39.695390 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-06 00:39:39.702676 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.5 MB/s eta 0:00:00
2026-02-06 00:39:39.737087 | controller | Collecting pluggy<2,>=1.5
2026-02-06 00:39:39.740455 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-06 00:39:39.798090 | controller | Collecting pygments>=2.7.2
2026-02-06 00:39:39.801339 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-06 00:39:39.828350 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 53.7 MB/s eta 0:00:00
2026-02-06 00:39:39.896763 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-06 00:39:40.971515 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-02-06 00:39:40.980468 | controller |
2026-02-06 00:39:41.047099 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-06 00:39:41.047164 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-06 00:39:41.260130 | controller | ok: Runtime: 0:00:26.120216
2026-02-06 00:39:41.275352 | 
2026-02-06 00:39:41.275523 | TASK [Update pip]
2026-02-06 00:39:41.824574 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-06 00:39:54.277829 | controller | Collecting pip
2026-02-06 00:40:06.469268 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-06 00:40:06.639626 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 10.8 MB/s eta 0:00:00
2026-02-06 00:40:06.704009 | controller | Installing collected packages: pip
2026-02-06 00:40:06.704241 | controller |   Attempting uninstall: pip
2026-02-06 00:40:06.706356 | controller |     Found existing installation: pip 22.2.2
2026-02-06 00:40:06.844681 | controller |     Uninstalling pip-22.2.2:
2026-02-06 00:40:06.859840 | controller |       Successfully uninstalled pip-22.2.2
2026-02-06 00:40:08.016621 | controller | Successfully installed pip-26.0.1
2026-02-06 00:40:08.359439 | controller | ok: Runtime: 0:00:26.573457
2026-02-06 00:40:08.375407 | 
2026-02-06 00:40:08.375581 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-06 00:40:08.613234 | controller | changed
2026-02-06 00:40:08.626627 | 
2026-02-06 00:40:08.626834 | TASK [Install ansible into virtualenv]
2026-02-06 00:40:09.202111 | controller | Processing ./src/github.com/ansible/ansible
2026-02-06 00:40:09.204416 | controller |   Installing build dependencies: started
2026-02-06 00:40:29.570967 | controller |   Installing build dependencies: finished with status 'done'
2026-02-06 00:40:29.572087 | controller |   Getting requirements to build wheel: started
2026-02-06 00:40:30.317347 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-06 00:40:30.318990 | controller |   Preparing metadata (pyproject.toml): started
2026-02-06 00:40:30.784008 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-06 00:40:30.788589 | 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-02-06 00:40:30.791981 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-06 00:40:31.223315 | controller | ERROR
2026-02-06 00:40:31.223485 | controller | {
2026-02-06 00:40:31.223536 | controller |   "delta": "0:00:21.946232",
2026-02-06 00:40:31.223569 | controller |   "end": "2026-02-06 00:40:30.856401",
2026-02-06 00:40:31.223598 | controller |   "msg": "non-zero return code",
2026-02-06 00:40:31.223639 | controller |   "rc": 1,
2026-02-06 00:40:31.223669 | controller |   "start": "2026-02-06 00:40:08.910169"
2026-02-06 00:40:31.223725 | controller | }
failure
2026-02-06 00:40:31.225814 | 
2026-02-06 00:40:31.225873 | PLAY RECAP
2026-02-06 00:40:31.225933 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-06 00:40:31.225965 | 
2026-02-06 00:40:31.374382 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-06 00:40:31.376383 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-06 00:40:31.976371 | 
2026-02-06 00:40:31.976500 | PLAY [all]
2026-02-06 00:40:31.997733 | 
2026-02-06 00:40:31.997823 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-06 00:40:32.263428 | controller | changed: non-zero return code
2026-02-06 00:40:32.278863 | 
2026-02-06 00:40:32.279064 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-06 00:40:32.295037 | controller | skipping: Conditional result was False
2026-02-06 00:40:32.309057 | 
2026-02-06 00:40:32.309221 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-06 00:40:32.333934 | 
2026-02-06 00:40:32.334103 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-06 00:40:32.356872 | 
2026-02-06 00:40:32.357073 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-06 00:40:32.372070 | controller | skipping: Conditional result was False
2026-02-06 00:40:32.382865 | 
2026-02-06 00:40:32.382976 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-06 00:40:32.404892 | 
2026-02-06 00:40:32.405062 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-06 00:40:32.419940 | controller | skipping: Conditional result was False
2026-02-06 00:40:32.427061 | 
2026-02-06 00:40:32.427155 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-06 00:40:32.441853 | controller | skipping: Conditional result was False
2026-02-06 00:40:32.449265 | 
2026-02-06 00:40:32.449365 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-06 00:40:32.467378 | controller | skipping: Conditional result was False
2026-02-06 00:40:32.497856 | 
2026-02-06 00:40:32.497941 | PLAY RECAP
2026-02-06 00:40:32.497981 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-06 00:40:32.498001 | 
2026-02-06 00:40:32.605032 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-06 00:40:32.605951 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-06 00:40:33.197065 | 
2026-02-06 00:40:33.197187 | PLAY [all:!appliance*]
2026-02-06 00:40:33.219778 | 
2026-02-06 00:40:33.219909 | TASK [unregister the node]
2026-02-06 00:40:33.752546 | controller | skipping: Conditional result was False
2026-02-06 00:40:33.766515 | 
2026-02-06 00:40:33.766778 | TASK [include_role : fetch-output]
2026-02-06 00:40:33.812221 | controller | ok
2026-02-06 00:40:33.839517 | 
2026-02-06 00:40:33.839658 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-06 00:40:33.906767 | controller | skipping: Conditional result was False
2026-02-06 00:40:33.915873 | 
2026-02-06 00:40:33.916000 | TASK [fetch-output : Set log path for single node]
2026-02-06 00:40:33.958257 | controller | ok
2026-02-06 00:40:33.965652 | 
2026-02-06 00:40:33.965848 | LOOP [fetch-output : Ensure local output dirs]
2026-02-06 00:40:34.368224 | controller -> localhost | ok: "/var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/logs"
2026-02-06 00:40:34.677238 | controller -> localhost | changed: "/var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/artifacts"
2026-02-06 00:40:34.908750 | controller -> localhost | changed: "/var/lib/zuul/builds/852827efe8714a2e9b8db084c740b53c/work/docs"
2026-02-06 00:40:34.938266 | 
2026-02-06 00:40:34.938525 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-06 00:40:35.672064 | controller | changed:
2026-02-06 00:40:35.672412 | controller | .d..t...... ./
2026-02-06 00:40:35.672488 | controller | cd+++++++++ controller/
2026-02-06 00:40:35.672553 | controller | changed: All items complete
2026-02-06 00:40:35.672597 | 
2026-02-06 00:40:36.237168 | controller | changed: .d..t...... ./
2026-02-06 00:40:36.746605 | controller | changed: .d..t...... ./
2026-02-06 00:40:36.766497 | 
2026-02-06 00:40:36.766717 | TASK [include_role : fetch-output-openshift]
2026-02-06 00:40:36.784090 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.796838 | 
2026-02-06 00:40:36.797033 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-06 00:40:36.837365 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.849283 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.916820 | 
2026-02-06 00:40:36.917010 | PLAY [localhost]
2026-02-06 00:40:36.937192 | 
2026-02-06 00:40:36.937365 | TASK [Run Zuul manifest role]
2026-02-06 00:40:36.961795 | localhost | ok
2026-02-06 00:40:36.982481 | 
2026-02-06 00:40:36.982694 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-06 00:40:37.434723 | localhost | changed
2026-02-06 00:40:37.441015 | 
2026-02-06 00:40:37.441094 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-06 00:40:37.484126 | localhost | ok
2026-02-06 00:40:37.492922 | 
2026-02-06 00:40:37.492997 | TASK [Set zuul-log-path fact]
2026-02-06 00:40:37.529356 | localhost | ok
2026-02-06 00:40:37.553337 | 
2026-02-06 00:40:37.553466 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-06 00:40:37.598425 | localhost | ok
2026-02-06 00:40:37.610879 | 
2026-02-06 00:40:37.610998 | LOOP [Run upload-logs-swift role]
2026-02-06 00:40:37.658970 | localhost | Output suppressed because no_log was given
2026-02-06 00:40:37.697377 | 
2026-02-06 00:40:37.697529 | TASK [Set zuul-log-path fact]
2026-02-06 00:40:37.744526 | localhost | skipping: Conditional result was False
2026-02-06 00:40:37.754023 | 
2026-02-06 00:40:37.754119 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-06 00:40:38.183356 | localhost -> localhost | ok: Runtime: 0:00:00.010263
2026-02-06 00:40:38.194607 | 
2026-02-06 00:40:38.194806 | TASK [upload-logs-swift : Upload logs to swift]