2026-02-14 00:06:34.827720 | Job console starting...
2026-02-14 00:06:34.836804 | Updating repositories
2026-02-14 00:06:35.106654 | Preparing job workspace
2026-02-14 00:06:39.086753 | Running Ansible setup...
2026-02-14 00:06:43.623629 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-14 00:06:44.295415 | 
2026-02-14 00:06:44.295527 | PLAY [localhost]
2026-02-14 00:06:44.303826 | 
2026-02-14 00:06:44.303896 | TASK [Gathering Facts]
2026-02-14 00:06:45.549556 | localhost | ok
2026-02-14 00:06:45.563311 | 
2026-02-14 00:06:45.563446 | TASK [Setup log path fact]
2026-02-14 00:06:45.583277 | localhost | ok
2026-02-14 00:06:45.599430 | 
2026-02-14 00:06:45.599568 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-14 00:06:45.628909 | localhost | ok
2026-02-14 00:06:45.638883 | 
2026-02-14 00:06:45.639037 | TASK [emit-job-header : Print job information]
2026-02-14 00:06:45.679349 | # Job Information
2026-02-14 00:06:45.679524 | Ansible Version: 2.15.12
2026-02-14 00:06:45.679560 | Job: ansible-test-sanity-docker-devel
2026-02-14 00:06:45.679586 | Pipeline: periodic
2026-02-14 00:06:45.679609 | Executor: ze04.softwarefactory-project.io
2026-02-14 00:06:45.679631 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-14 00:06:45.679656 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/90a/ansible/90acf2fd76f54eac9b4f40712d17bbfd/
2026-02-14 00:06:45.679699 | Event ID: 343d777a1a684010b2f6abf2a6f30cb9
2026-02-14 00:06:45.685174 | 
2026-02-14 00:06:45.685257 | LOOP [emit-job-header : Print node information]
2026-02-14 00:06:45.830636 | localhost | ok:
2026-02-14 00:06:45.830827 | localhost | # Node Information
2026-02-14 00:06:45.830859 | localhost | Inventory Hostname: controller
2026-02-14 00:06:45.830883 | localhost | Hostname: np0005619344
2026-02-14 00:06:45.830907 | localhost | Username: zuul
2026-02-14 00:06:45.830934 | localhost | Distro: Fedora 37
2026-02-14 00:06:45.830956 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-14 00:06:45.830978 | localhost | Region: ca-ymq-1
2026-02-14 00:06:45.830999 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-14 00:06:45.831019 | localhost | Product Name: OpenStack Nova
2026-02-14 00:06:45.831040 | localhost | Interface IP: 162.253.55.200
2026-02-14 00:06:45.843352 | 
2026-02-14 00:06:45.843481 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-14 00:06:46.338803 | localhost -> localhost | changed
2026-02-14 00:06:46.353458 | 
2026-02-14 00:06:46.353579 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-14 00:06:47.291479 | localhost -> localhost | changed
2026-02-14 00:06:47.312423 | 
2026-02-14 00:06:47.312512 | PLAY [all:!appliance*]
2026-02-14 00:06:47.329468 | 
2026-02-14 00:06:47.329563 | TASK [include_role : start-zuul-console]
2026-02-14 00:06:47.349598 | controller | ok
2026-02-14 00:06:47.364025 | 
2026-02-14 00:06:47.364125 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-14 00:06:47.734392 | controller | ok
2026-02-14 00:06:47.766244 | 
2026-02-14 00:06:47.766390 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-14 00:06:49.148755 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-14 00:06:49.156762 | 
2026-02-14 00:06:49.156933 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-14 00:06:49.696103 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.715167 | 
2026-02-14 00:06:49.715413 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-14 00:06:49.744887 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.762641 | 
2026-02-14 00:06:49.762920 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-14 00:06:49.793440 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.804565 | 
2026-02-14 00:06:49.804713 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-14 00:06:49.842239 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.852600 | 
2026-02-14 00:06:49.852748 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-14 00:06:49.880204 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.892741 | 
2026-02-14 00:06:49.892904 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-14 00:06:49.921375 | controller | skipping: Conditional result was False
2026-02-14 00:06:49.941160 | 
2026-02-14 00:06:49.941392 | TASK [Disable Fedora Modular]
2026-02-14 00:06:50.222580 | controller | changed
2026-02-14 00:06:50.231644 | 
2026-02-14 00:06:50.231781 | TASK [Enable EPEL]
2026-02-14 00:06:50.257935 | controller | skipping: Conditional result was False
2026-02-14 00:06:50.273446 | 
2026-02-14 00:06:50.273719 | TASK [Register the RHEL node]
2026-02-14 00:06:50.828178 | 
2026-02-14 00:06:50.828338 | TASK [Show the subscription-manager status]
2026-02-14 00:06:51.392209 | controller | skipping: Conditional result was False
2026-02-14 00:06:51.406549 | 
2026-02-14 00:06:51.406756 | TASK [Enable EPEL on RHEL]
2026-02-14 00:06:51.960445 | controller | skipping: Conditional result was False
2026-02-14 00:06:51.969491 | 
2026-02-14 00:06:51.969605 | TASK [Install git and tox]
2026-02-14 00:08:20.040613 | controller | changed
2026-02-14 00:08:20.049887 | 
2026-02-14 00:08:20.050001 | TASK [include_role : prepare-workspace]
2026-02-14 00:08:20.083420 | controller | ok
2026-02-14 00:08:20.117649 | 
2026-02-14 00:08:20.117832 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-14 00:08:20.351412 | controller | ok
2026-02-14 00:08:20.370272 | 
2026-02-14 00:08:20.370505 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-14 00:08:35.691322 | controller | Output suppressed because no_log was given
2026-02-14 00:08:35.712440 | 
2026-02-14 00:08:35.712654 | TASK [include_role : prepare-workspace-openshift]
2026-02-14 00:08:35.739394 | controller | skipping: Conditional result was False
2026-02-14 00:08:35.810818 | 
2026-02-14 00:08:35.810915 | PLAY [all:!appliance]
2026-02-14 00:08:35.830746 | 
2026-02-14 00:08:35.830825 | TASK [Run add-build-sshkey role (RSA)]
2026-02-14 00:08:35.861944 | controller | ok
2026-02-14 00:08:35.881868 | 
2026-02-14 00:08:35.881963 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-14 00:08:36.154106 | controller -> localhost | ok
2026-02-14 00:08:36.166950 | 
2026-02-14 00:08:36.167096 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-14 00:08:36.196374 | controller | ok
2026-02-14 00:08:36.219510 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-14 00:08:36.229963 | 
2026-02-14 00:08:36.230077 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-14 00:08:36.727213 | controller -> localhost | Generating public/private rsa key pair.
2026-02-14 00:08:36.727408 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_rsa.
2026-02-14 00:08:36.727440 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_rsa.pub.
2026-02-14 00:08:36.727463 | controller -> localhost | The key fingerprint is:
2026-02-14 00:08:36.727484 | controller -> localhost | SHA256:q1zNeET79zAu1v0f+0oqn0OaE5qiMCvNmQ/RNz09nxk zuul-build-sshkey
2026-02-14 00:08:36.727506 | controller -> localhost | The key's randomart image is:
2026-02-14 00:08:36.727526 | controller -> localhost | +---[RSA 2048]----+
2026-02-14 00:08:36.727546 | controller -> localhost | |                 |
2026-02-14 00:08:36.727567 | controller -> localhost | |                 |
2026-02-14 00:08:36.727588 | controller -> localhost | |          .      |
2026-02-14 00:08:36.727607 | controller -> localhost | |   .   . o .     |
2026-02-14 00:08:36.727627 | controller -> localhost | |  . . o S = E    |
2026-02-14 00:08:36.727657 | controller -> localhost | |   . . . B.+.+   |
2026-02-14 00:08:36.727702 | controller -> localhost | | o+o    +o+==.=o |
2026-02-14 00:08:36.727730 | controller -> localhost | |. == ..oo.= +*.++|
2026-02-14 00:08:36.727751 | controller -> localhost | | ...o.o.   =+oooO|
2026-02-14 00:08:36.727774 | controller -> localhost | +----[SHA256]-----+
2026-02-14 00:08:36.727819 | controller -> localhost | ok: Runtime: 0:00:00.093042
2026-02-14 00:08:36.738866 | 
2026-02-14 00:08:36.738971 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-14 00:08:36.758890 | controller | ok
2026-02-14 00:08:36.769628 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-14 00:08:36.778714 | 
2026-02-14 00:08:36.778781 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-14 00:08:36.794328 | controller | skipping: Conditional result was False
2026-02-14 00:08:36.802167 | 
2026-02-14 00:08:36.802235 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-14 00:13:42.470880 | controller | changed
2026-02-14 00:13:42.498845 | 
2026-02-14 00:13:42.498966 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-14 00:13:42.703967 | controller | ok
2026-02-14 00:13:42.712052 | 
2026-02-14 00:13:42.712156 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-14 00:13:43.325320 | controller | changed
2026-02-14 00:13:43.340881 | 
2026-02-14 00:13:43.340994 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-14 00:13:43.942755 | controller | changed
2026-02-14 00:13:43.950224 | 
2026-02-14 00:13:43.950337 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-14 00:13:43.975588 | controller | skipping: Conditional result was False
2026-02-14 00:13:43.982564 | 
2026-02-14 00:13:43.982665 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-14 00:13:44.380406 | controller -> localhost | changed
2026-02-14 00:13:44.396419 | 
2026-02-14 00:13:44.396538 | TASK [add-build-sshkey : Add back temp key]
2026-02-14 00:13:44.710006 | controller -> localhost | Identity added: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_rsa (zuul-build-sshkey)
2026-02-14 00:13:44.710214 | controller -> localhost | ok: Runtime: 0:00:00.027721
2026-02-14 00:13:44.718120 | 
2026-02-14 00:13:44.718227 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-14 00:13:45.069501 | controller | ok
2026-02-14 00:13:45.078083 | 
2026-02-14 00:13:45.078192 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-14 00:13:45.104418 | controller | skipping: Conditional result was False
2026-02-14 00:13:45.121146 | 
2026-02-14 00:13:45.121261 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-14 00:13:45.142411 | controller | ok
2026-02-14 00:13:45.200347 | 
2026-02-14 00:13:45.200466 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-14 00:13:45.417855 | controller -> localhost | ok
2026-02-14 00:13:45.429622 | 
2026-02-14 00:13:45.429760 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-14 00:13:45.469846 | controller | ok
2026-02-14 00:13:45.482772 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-14 00:13:45.490285 | 
2026-02-14 00:13:45.490397 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-14 00:13:45.769870 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-14 00:13:45.770047 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_ecdsa.
2026-02-14 00:13:45.770075 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_ecdsa.pub.
2026-02-14 00:13:45.770110 | controller -> localhost | The key fingerprint is:
2026-02-14 00:13:45.770132 | controller -> localhost | SHA256:5gd6ba3gFizn52Prtpes7W/5ODy56iyAy5udT60hxic zuul-build-sshkey
2026-02-14 00:13:45.770153 | controller -> localhost | The key's randomart image is:
2026-02-14 00:13:45.770173 | controller -> localhost | +---[ECDSA 521]---+
2026-02-14 00:13:45.770192 | controller -> localhost | |                 |
2026-02-14 00:13:45.770211 | controller -> localhost | |                 |
2026-02-14 00:13:45.770230 | controller -> localhost | |                 |
2026-02-14 00:13:45.770248 | controller -> localhost | |                 |
2026-02-14 00:13:45.770267 | controller -> localhost | |       oS        |
2026-02-14 00:13:45.770286 | controller -> localhost | |      o==o o     |
2026-02-14 00:13:45.770305 | controller -> localhost | |     ..=EoB.oo o |
2026-02-14 00:13:45.770323 | controller -> localhost | |      o*oX**+ B. |
2026-02-14 00:13:45.770341 | controller -> localhost | |      oo+BXX*++=.|
2026-02-14 00:13:45.770359 | controller -> localhost | +----[SHA256]-----+
2026-02-14 00:13:45.770407 | controller -> localhost | ok: Runtime: 0:00:00.011281
2026-02-14 00:13:45.778413 | 
2026-02-14 00:13:45.778524 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-14 00:13:45.819699 | controller | ok
2026-02-14 00:13:45.827401 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-14 00:13:45.837810 | 
2026-02-14 00:13:45.837937 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-14 00:13:45.862198 | controller | skipping: Conditional result was False
2026-02-14 00:13:45.869546 | 
2026-02-14 00:13:45.869671 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-14 00:13:46.127257 | controller | changed
2026-02-14 00:13:46.137993 | 
2026-02-14 00:13:46.138120 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-14 00:13:46.372939 | controller | ok
2026-02-14 00:13:46.379621 | 
2026-02-14 00:13:46.379741 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-14 00:13:46.999491 | controller | changed
2026-02-14 00:13:47.014727 | 
2026-02-14 00:13:47.014883 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-14 00:13:47.618094 | controller | changed
2026-02-14 00:13:47.627477 | 
2026-02-14 00:13:47.627624 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-14 00:13:47.643430 | controller | skipping: Conditional result was False
2026-02-14 00:13:47.651618 | 
2026-02-14 00:13:47.651774 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-14 00:13:47.943342 | controller -> localhost | changed
2026-02-14 00:13:47.958439 | 
2026-02-14 00:13:47.958578 | TASK [add-build-sshkey : Add back temp key]
2026-02-14 00:13:48.258098 | controller -> localhost | Identity added: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/90acf2fd76f54eac9b4f40712d17bbfd_id_ecdsa (zuul-build-sshkey)
2026-02-14 00:13:48.258295 | controller -> localhost | ok: Runtime: 0:00:00.008197
2026-02-14 00:13:48.265630 | 
2026-02-14 00:13:48.265769 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-14 00:13:48.460274 | controller | ok
2026-02-14 00:13:48.466378 | 
2026-02-14 00:13:48.466471 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-14 00:13:48.491481 | controller | skipping: Conditional result was False
2026-02-14 00:13:48.506087 | 
2026-02-14 00:13:48.506197 | TASK [include_role : remove-zuul-sshkey]
2026-02-14 00:13:48.521432 | controller | skipping: Conditional result was False
2026-02-14 00:13:48.531924 | 
2026-02-14 00:13:48.532063 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-14 00:13:48.744700 | controller | ok: "logs"
2026-02-14 00:13:48.748986 | controller | ok: All items complete
2026-02-14 00:13:48.749049 | 
2026-02-14 00:13:48.950800 | controller | ok: "artifacts"
2026-02-14 00:13:49.152914 | controller | ok: "docs"
2026-02-14 00:13:49.176403 | 
2026-02-14 00:13:49.176627 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-14 00:13:49.417059 | controller | changed: "logs"
2026-02-14 00:13:49.625360 | controller | changed: "artifacts"
2026-02-14 00:13:49.824236 | controller | changed: "docs"
2026-02-14 00:13:49.876641 | 
2026-02-14 00:13:49.876810 | PLAY RECAP
2026-02-14 00:13:49.876890 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-14 00:13:49.876948 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-14 00:13:49.876977 | 
2026-02-14 00:13:50.011338 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-14 00:13:50.012350 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-14 00:13:50.629739 | 
2026-02-14 00:13:50.629848 | PLAY [all]
2026-02-14 00:13:50.652827 | 
2026-02-14 00:13:50.652946 | TASK [Install binary dependencies]
2026-02-14 00:13:50.693581 | controller | ok
2026-02-14 00:13:50.719568 | 
2026-02-14 00:13:50.719728 | TASK [bindep : Include find tasks]
2026-02-14 00:13:50.750605 | controller | ok
2026-02-14 00:13:50.759518 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-14 00:13:50.767080 | 
2026-02-14 00:13:50.767220 | TASK [bindep : Look for bindep.txt]
2026-02-14 00:13:51.338693 | controller | ok
2026-02-14 00:13:51.349621 | 
2026-02-14 00:13:51.349790 | TASK [bindep : Define bindep_file fact]
2026-02-14 00:13:51.374811 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.382882 | 
2026-02-14 00:13:51.382985 | TASK [bindep : Look for other-requirements.txt]
2026-02-14 00:13:51.605622 | controller | ok
2026-02-14 00:13:51.612174 | 
2026-02-14 00:13:51.612284 | TASK [bindep : Define bindep_file fact]
2026-02-14 00:13:51.648443 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.659500 | 
2026-02-14 00:13:51.659664 | TASK [bindep : Look for bindep fallback file]
2026-02-14 00:13:51.695999 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.710272 | 
2026-02-14 00:13:51.714495 | TASK [bindep : Define bindep_file fact]
2026-02-14 00:13:51.740141 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.752144 | 
2026-02-14 00:13:51.752300 | TASK [bindep : Include bindep tasks]
2026-02-14 00:13:51.778575 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.786269 | 
2026-02-14 00:13:51.786386 | TASK [bindep : Include install tasks]
2026-02-14 00:13:51.810953 | controller | skipping: Conditional result was False
2026-02-14 00:13:51.817569 | 
2026-02-14 00:13:51.817676 | LOOP [bindep : Include package tasks]
2026-02-14 00:13:51.888887 | 
2026-02-14 00:13:51.889090 | TASK [Run test-setup role]
2026-02-14 00:13:51.914611 | controller | ok
2026-02-14 00:13:51.962035 | 
2026-02-14 00:13:51.962217 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-14 00:13:52.165444 | controller | ok
2026-02-14 00:13:52.171546 | 
2026-02-14 00:13:52.171610 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-14 00:13:52.703415 | controller | skipping: Conditional result was False
2026-02-14 00:13:52.739721 | 
2026-02-14 00:13:52.739844 | PLAY RECAP
2026-02-14 00:13:52.739890 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-14 00:13:52.739913 | 
2026-02-14 00:13:52.849878 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-14 00:13:52.851182 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-14 00:13:53.472119 | 
2026-02-14 00:13:53.472252 | PLAY [controller]
2026-02-14 00:13:53.494728 | 
2026-02-14 00:13:53.494849 | TASK [Create the /root directory]
2026-02-14 00:13:54.053451 | controller | ok
2026-02-14 00:13:54.068288 | 
2026-02-14 00:13:54.068513 | TASK [Install glibc-langpack-en]
2026-02-14 00:13:57.894755 | controller | ok: Nothing to do
2026-02-14 00:13:57.902545 | 
2026-02-14 00:13:57.902627 | TASK [Ensure controller directory exists]
2026-02-14 00:13:58.113244 | controller | changed
2026-02-14 00:13:58.128165 | 
2026-02-14 00:13:58.128343 | TASK [Install container runtime]
2026-02-14 00:13:58.211225 | controller | ok
2026-02-14 00:13:58.273103 | 
2026-02-14 00:13:58.273243 | LOOP [ensure-podman : Find distribution installation]
2026-02-14 00:13:58.302896 | controller | ok: "/var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-14 00:13:58.326898 | controller | included: /var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-14 00:13:58.344417 | 
2026-02-14 00:13:58.344598 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-14 00:15:03.117638 | controller | changed
2026-02-14 00:15:03.132259 | 
2026-02-14 00:15:03.132413 | TASK [ensure-podman : Fetch podman version]
2026-02-14 00:15:03.701143 | controller | Client:       Podman Engine
2026-02-14 00:15:03.701242 | controller | Version:      4.6.2
2026-02-14 00:15:03.701287 | controller | API Version:  4.6.2
2026-02-14 00:15:03.701330 | controller | Go Version:   go1.19.12
2026-02-14 00:15:03.701380 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-14 00:15:03.701424 | controller | OS/Arch:      linux/amd64
2026-02-14 00:15:04.182226 | controller | ok: Runtime: 0:00:00.193896
2026-02-14 00:15:04.197507 | 
2026-02-14 00:15:04.197724 | TASK [ensure-podman : Print podman version installed]
2026-02-14 00:15:04.237565 | Podman version: Client:       Podman Engine
2026-02-14 00:15:04.237848 | Version:      4.6.2
2026-02-14 00:15:04.237890 | API Version:  4.6.2
2026-02-14 00:15:04.237922 | Go Version:   go1.19.12
2026-02-14 00:15:04.237948 | Built:        Mon Aug 28 19:38:31 2023
2026-02-14 00:15:04.237977 | OS/Arch:      linux/amd64
2026-02-14 00:15:04.247379 | 
2026-02-14 00:15:04.247510 | TASK [ensure-podman : Validate podman engine]
2026-02-14 00:15:04.792850 | controller | skipping: Conditional result was False
2026-02-14 00:15:04.808823 | 
2026-02-14 00:15:04.808983 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-14 00:15:04.826546 | controller | skipping: Conditional result was False
2026-02-14 00:15:04.856468 | 
2026-02-14 00:15:04.856595 | TASK [Ensure python3.8 is present]
2026-02-14 00:15:04.871672 | controller | skipping: Conditional result was False
2026-02-14 00:15:04.884773 | 
2026-02-14 00:15:04.884914 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-14 00:15:04.909828 | controller | ok
2026-02-14 00:15:04.963165 | 
2026-02-14 00:15:04.963330 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-14 00:15:06.368967 | controller | ok: Nothing to do
2026-02-14 00:15:06.375324 | 
2026-02-14 00:15:06.375393 | TASK [our-ensure-python : Also install python3-devel]
2026-02-14 00:15:16.099091 | controller | changed
2026-02-14 00:15:16.125426 | 
2026-02-14 00:15:16.125569 | TASK [Run ensure-virtualenv role]
2026-02-14 00:15:16.151286 | controller | ok
2026-02-14 00:15:16.186099 | 
2026-02-14 00:15:16.186249 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-14 00:15:16.407082 | controller | /usr/bin/virtualenv
2026-02-14 00:15:16.723339 | controller | ok: Runtime: 0:00:00.005119
2026-02-14 00:15:16.736634 | 
2026-02-14 00:15:16.736831 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-14 00:15:16.795720 | controller | skipping: Conditional result was False
2026-02-14 00:15:16.796185 | controller | ok: All items complete
2026-02-14 00:15:16.796253 | 
2026-02-14 00:15:16.831808 | 
2026-02-14 00:15:16.831998 | TASK [Find the full path of the Python interpreter]
2026-02-14 00:15:17.107028 | controller | /usr/bin/python3
2026-02-14 00:15:17.408367 | controller | ok
2026-02-14 00:15:17.414296 | 
2026-02-14 00:15:17.414366 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-14 00:15:18.316151 | controller | created virtual environment CPython3.11.0.final.0-64 in 428ms
2026-02-14 00:15:18.335816 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-14 00:15:18.335832 | 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-14 00:15:18.335849 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-14 00:15:18.335862 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-14 00:15:18.447826 | controller | changed
2026-02-14 00:15:18.461299 | 
2026-02-14 00:15:18.461434 | TASK [Set selinux package]
2026-02-14 00:15:18.502250 | controller | ok
2026-02-14 00:15:18.513919 | 
2026-02-14 00:15:18.514049 | TASK [Set selinux package (Fedora)]
2026-02-14 00:15:18.567119 | controller | ok
2026-02-14 00:15:18.578940 | 
2026-02-14 00:15:18.579067 | TASK [Install selinux into virtualenv]
2026-02-14 00:15:44.037881 | controller | Collecting selinux-please-lie-to-me
2026-02-14 00:15:56.299615 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-14 00:15:56.606431 | controller | Collecting setuptools<50.0.0
2026-02-14 00:15:56.612742 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-14 00:15:56.652664 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.0 MB/s eta 0:00:00
2026-02-14 00:15:56.732571 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-14 00:15:56.732790 | controller |   Attempting uninstall: setuptools
2026-02-14 00:15:56.735219 | controller |     Found existing installation: setuptools 62.6.0
2026-02-14 00:15:56.794347 | controller |     Uninstalling setuptools-62.6.0:
2026-02-14 00:15:56.802352 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-14 00:15:57.157835 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-14 00:16:08.664060 | controller |
2026-02-14 00:16:08.744355 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-14 00:16:08.744407 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-14 00:16:09.166763 | controller | ok: Runtime: 0:00:49.943480
2026-02-14 00:16:09.173457 | 
2026-02-14 00:16:09.173563 | TASK [Install pytest-forked into virtualenv]
2026-02-14 00:16:18.869590 | controller | Collecting pytest-forked
2026-02-14 00:16:31.177780 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-14 00:16:31.224035 | controller | Collecting py
2026-02-14 00:16:31.227504 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-14 00:16:31.248236 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00
2026-02-14 00:16:31.358370 | controller | Collecting pytest>=3.10
2026-02-14 00:16:31.361806 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-14 00:16:31.380116 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.4 MB/s eta 0:00:00
2026-02-14 00:16:31.423986 | controller | Collecting iniconfig>=1.0.1
2026-02-14 00:16:31.427332 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-14 00:16:31.471495 | controller | Collecting packaging>=22
2026-02-14 00:16:31.475101 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-14 00:16:31.483591 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.0 MB/s eta 0:00:00
2026-02-14 00:16:31.515000 | controller | Collecting pluggy<2,>=1.5
2026-02-14 00:16:31.518046 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-14 00:16:31.568328 | controller | Collecting pygments>=2.7.2
2026-02-14 00:16:31.571556 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-14 00:16:31.598246 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 54.8 MB/s eta 0:00:00
2026-02-14 00:16:31.669753 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-14 00:16:32.733163 | 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-14 00:16:32.742031 | controller |
2026-02-14 00:16:32.811348 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-14 00:16:32.811394 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-14 00:16:33.247995 | controller | ok: Runtime: 0:00:23.372379
2026-02-14 00:16:33.257497 | 
2026-02-14 00:16:33.257642 | TASK [Update pip]
2026-02-14 00:16:33.801066 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-14 00:16:43.565411 | controller | Collecting pip
2026-02-14 00:16:55.755427 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-14 00:16:55.806129 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 37.5 MB/s eta 0:00:00
2026-02-14 00:16:55.870106 | controller | Installing collected packages: pip
2026-02-14 00:16:55.870339 | controller |   Attempting uninstall: pip
2026-02-14 00:16:55.872606 | controller |     Found existing installation: pip 22.2.2
2026-02-14 00:16:56.012199 | controller |     Uninstalling pip-22.2.2:
2026-02-14 00:16:56.027322 | controller |       Successfully uninstalled pip-22.2.2
2026-02-14 00:16:56.846900 | controller | Successfully installed pip-26.0.1
2026-02-14 00:16:57.334472 | controller | ok: Runtime: 0:00:23.417225
2026-02-14 00:16:57.349538 | 
2026-02-14 00:16:57.349794 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-14 00:16:57.571968 | controller | changed
2026-02-14 00:16:57.586873 | 
2026-02-14 00:16:57.587003 | TASK [Install ansible into virtualenv]
2026-02-14 00:16:58.093399 | controller | Processing ./src/github.com/ansible/ansible
2026-02-14 00:16:58.095809 | controller |   Installing build dependencies: started
2026-02-14 00:17:21.265551 | controller |   Installing build dependencies: finished with status 'done'
2026-02-14 00:17:21.266163 | controller |   Getting requirements to build wheel: started
2026-02-14 00:17:22.014863 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-14 00:17:22.015715 | controller |   Preparing metadata (pyproject.toml): started
2026-02-14 00:17:22.513480 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-14 00:17:22.515961 | 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-14 00:17:22.518437 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-14 00:17:22.648172 | controller | ERROR
2026-02-14 00:17:22.648296 | controller | {
2026-02-14 00:17:22.648326 | controller |   "delta": "0:00:24.770569",
2026-02-14 00:17:22.648345 | controller |   "end": "2026-02-14 00:17:22.584596",
2026-02-14 00:17:22.648362 | controller |   "msg": "non-zero return code",
2026-02-14 00:17:22.648386 | controller |   "rc": 1,
2026-02-14 00:17:22.648404 | controller |   "start": "2026-02-14 00:16:57.814027"
2026-02-14 00:17:22.648419 | controller | }
failure
2026-02-14 00:17:22.649750 | 
2026-02-14 00:17:22.649799 | PLAY RECAP
2026-02-14 00:17:22.649841 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-14 00:17:22.649863 | 
2026-02-14 00:17:22.770119 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-14 00:17:22.771150 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-14 00:17:23.381431 | 
2026-02-14 00:17:23.381546 | PLAY [all]
2026-02-14 00:17:23.403827 | 
2026-02-14 00:17:23.403959 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-14 00:17:23.857409 | controller | changed: non-zero return code
2026-02-14 00:17:23.863505 | 
2026-02-14 00:17:23.863626 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-14 00:17:23.878127 | controller | skipping: Conditional result was False
2026-02-14 00:17:23.884458 | 
2026-02-14 00:17:23.884570 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-14 00:17:23.906952 | 
2026-02-14 00:17:23.907108 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-14 00:17:23.949163 | 
2026-02-14 00:17:23.949575 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-14 00:17:23.979188 | controller | skipping: Conditional result was False
2026-02-14 00:17:24.015499 | 
2026-02-14 00:17:24.015659 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-14 00:17:24.042951 | 
2026-02-14 00:17:24.043159 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-14 00:17:24.079213 | controller | skipping: Conditional result was False
2026-02-14 00:17:24.088739 | 
2026-02-14 00:17:24.089013 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-14 00:17:24.117246 | controller | skipping: Conditional result was False
2026-02-14 00:17:24.133624 | 
2026-02-14 00:17:24.133766 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-14 00:17:24.148945 | controller | skipping: Conditional result was False
2026-02-14 00:17:24.180270 | 
2026-02-14 00:17:24.180371 | PLAY RECAP
2026-02-14 00:17:24.180413 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-14 00:17:24.180433 | 
2026-02-14 00:17:24.297241 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-14 00:17:24.298330 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-14 00:17:24.953000 | 
2026-02-14 00:17:24.953186 | PLAY [all:!appliance*]
2026-02-14 00:17:24.990541 | 
2026-02-14 00:17:24.990699 | TASK [unregister the node]
2026-02-14 00:17:25.539737 | controller | skipping: Conditional result was False
2026-02-14 00:17:25.548178 | 
2026-02-14 00:17:25.548318 | TASK [include_role : fetch-output]
2026-02-14 00:17:25.581174 | controller | ok
2026-02-14 00:17:25.611250 | 
2026-02-14 00:17:25.611393 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-14 00:17:25.656796 | controller | skipping: Conditional result was False
2026-02-14 00:17:25.665926 | 
2026-02-14 00:17:25.666149 | TASK [fetch-output : Set log path for single node]
2026-02-14 00:17:25.710159 | controller | ok
2026-02-14 00:17:25.721940 | 
2026-02-14 00:17:25.722163 | LOOP [fetch-output : Ensure local output dirs]
2026-02-14 00:17:26.147191 | controller -> localhost | ok: "/var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/logs"
2026-02-14 00:17:26.416924 | controller -> localhost | changed: "/var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/artifacts"
2026-02-14 00:17:26.671518 | controller -> localhost | changed: "/var/lib/zuul/builds/90acf2fd76f54eac9b4f40712d17bbfd/work/docs"
2026-02-14 00:17:26.686918 | 
2026-02-14 00:17:26.687053 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-14 00:17:27.406744 | controller | changed:
2026-02-14 00:17:27.407029 | controller | .d..t...... ./
2026-02-14 00:17:27.407083 | controller | cd+++++++++ controller/
2026-02-14 00:17:27.407142 | controller | changed: All items complete
2026-02-14 00:17:27.407179 | 
2026-02-14 00:17:27.876592 | controller | changed: .d..t...... ./
2026-02-14 00:17:28.339913 | controller | changed: .d..t...... ./
2026-02-14 00:17:28.365301 | 
2026-02-14 00:17:28.365426 | TASK [include_role : fetch-output-openshift]
2026-02-14 00:17:28.379324 | controller | skipping: Conditional result was False
2026-02-14 00:17:28.386737 | 
2026-02-14 00:17:28.386830 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-14 00:17:28.412962 | controller | skipping: Conditional result was False
2026-02-14 00:17:28.428284 | controller | skipping: Conditional result was False
2026-02-14 00:17:28.463915 | 
2026-02-14 00:17:28.464116 | PLAY [localhost]
2026-02-14 00:17:28.480106 | 
2026-02-14 00:17:28.480187 | TASK [Run Zuul manifest role]
2026-02-14 00:17:28.506411 | localhost | ok
2026-02-14 00:17:28.524664 | 
2026-02-14 00:17:28.524799 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-14 00:17:28.973834 | localhost | changed
2026-02-14 00:17:28.987958 | 
2026-02-14 00:17:28.988284 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-14 00:17:29.025538 | localhost | ok
2026-02-14 00:17:29.042275 | 
2026-02-14 00:17:29.042377 | TASK [Set zuul-log-path fact]
2026-02-14 00:17:29.064062 | localhost | ok
2026-02-14 00:17:29.087041 | 
2026-02-14 00:17:29.087176 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-14 00:17:29.130005 | localhost | ok
2026-02-14 00:17:29.151386 | 
2026-02-14 00:17:29.151606 | LOOP [Run upload-logs-swift role]
2026-02-14 00:17:29.189881 | localhost | Output suppressed because no_log was given
2026-02-14 00:17:29.221060 | 
2026-02-14 00:17:29.221168 | TASK [Set zuul-log-path fact]
2026-02-14 00:17:29.245201 | localhost | skipping: Conditional result was False
2026-02-14 00:17:29.252459 | 
2026-02-14 00:17:29.252570 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-14 00:17:29.806716 | localhost -> localhost | ok: Runtime: 0:00:00.006443
2026-02-14 00:17:29.825120 | 
2026-02-14 00:17:29.825255 | TASK [upload-logs-swift : Upload logs to swift]