2026-02-06 00:34:48.046282 | Job console starting...
2026-02-06 00:34:48.058276 | Updating repositories
2026-02-06 00:34:48.221491 | Preparing job workspace
2026-02-06 00:34:52.440373 | Running Ansible setup...
2026-02-06 00:34:57.566177 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-06 00:34:58.193442 | 
2026-02-06 00:34:58.193564 | PLAY [localhost]
2026-02-06 00:34:58.201848 | 
2026-02-06 00:34:58.201921 | TASK [Gathering Facts]
2026-02-06 00:34:59.251038 | localhost | ok
2026-02-06 00:34:59.272541 | 
2026-02-06 00:34:59.272727 | TASK [Setup log path fact]
2026-02-06 00:34:59.292965 | localhost | ok
2026-02-06 00:34:59.305463 | 
2026-02-06 00:34:59.305549 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-06 00:34:59.333335 | localhost | ok
2026-02-06 00:34:59.341287 | 
2026-02-06 00:34:59.341361 | TASK [emit-job-header : Print job information]
2026-02-06 00:34:59.379882 | # Job Information
2026-02-06 00:34:59.380089 | Ansible Version: 2.15.12
2026-02-06 00:34:59.380130 | Job: ansible-test-sanity-docker-milestone
2026-02-06 00:34:59.380154 | Pipeline: periodic
2026-02-06 00:34:59.380173 | Executor: ze01.softwarefactory-project.io
2026-02-06 00:34:59.380191 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-06 00:34:59.380214 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/5af/ansible/5af98248e2bd45f89b01441a60728628/
2026-02-06 00:34:59.380233 | Event ID: ebfa20167ca74e4389cc224acfe9a040
2026-02-06 00:34:59.384029 | 
2026-02-06 00:34:59.384091 | LOOP [emit-job-header : Print node information]
2026-02-06 00:34:59.498994 | localhost | ok:
2026-02-06 00:34:59.499286 | localhost | # Node Information
2026-02-06 00:34:59.499321 | localhost | Inventory Hostname: controller
2026-02-06 00:34:59.499342 | localhost | Hostname: np0005610386
2026-02-06 00:34:59.499360 | localhost | Username: zuul
2026-02-06 00:34:59.499385 | localhost | Distro: Fedora 37
2026-02-06 00:34:59.499404 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-06 00:34:59.499421 | localhost | Region: ca-ymq-1
2026-02-06 00:34:59.499437 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-06 00:34:59.499453 | localhost | Product Name: OpenStack Nova
2026-02-06 00:34:59.499469 | localhost | Interface IP: 199.204.45.131
2026-02-06 00:34:59.520525 | 
2026-02-06 00:34:59.520661 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-06 00:34:59.943744 | localhost -> localhost | changed
2026-02-06 00:34:59.949102 | 
2026-02-06 00:34:59.949195 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-06 00:35:00.860058 | localhost -> localhost | changed
2026-02-06 00:35:00.881883 | 
2026-02-06 00:35:00.881961 | PLAY [all:!appliance*]
2026-02-06 00:35:00.900226 | 
2026-02-06 00:35:00.900313 | TASK [include_role : start-zuul-console]
2026-02-06 00:35:00.920007 | controller | ok
2026-02-06 00:35:00.933915 | 
2026-02-06 00:35:00.933991 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-06 00:35:01.313615 | controller | ok
2026-02-06 00:35:01.328230 | 
2026-02-06 00:35:01.328350 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-06 00:35:03.018049 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-06 00:35:03.026558 | 
2026-02-06 00:35:03.026661 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-06 00:35:03.558557 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.573180 | 
2026-02-06 00:35:03.573331 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-06 00:35:03.601530 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.617067 | 
2026-02-06 00:35:03.617237 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-06 00:35:03.644392 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.658645 | 
2026-02-06 00:35:03.658818 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-06 00:35:03.686154 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.700311 | 
2026-02-06 00:35:03.700479 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-06 00:35:03.727185 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.745310 | 
2026-02-06 00:35:03.745534 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-06 00:35:03.775679 | controller | skipping: Conditional result was False
2026-02-06 00:35:03.805408 | 
2026-02-06 00:35:03.805649 | TASK [Disable Fedora Modular]
2026-02-06 00:35:04.060465 | controller | changed
2026-02-06 00:35:04.073621 | 
2026-02-06 00:35:04.073811 | TASK [Enable EPEL]
2026-02-06 00:35:04.100882 | controller | skipping: Conditional result was False
2026-02-06 00:35:04.114227 | 
2026-02-06 00:35:04.114387 | TASK [Register the RHEL node]
2026-02-06 00:35:04.677619 | 
2026-02-06 00:35:04.677906 | TASK [Show the subscription-manager status]
2026-02-06 00:35:05.261959 | controller | skipping: Conditional result was False
2026-02-06 00:35:05.277185 | 
2026-02-06 00:35:05.277333 | TASK [Enable EPEL on RHEL]
2026-02-06 00:35:05.833572 | controller | skipping: Conditional result was False
2026-02-06 00:35:05.849401 | 
2026-02-06 00:35:05.849591 | TASK [Install git and tox]
2026-02-06 00:36:38.656595 | controller | changed
2026-02-06 00:36:38.663367 | 
2026-02-06 00:36:38.663474 | TASK [include_role : prepare-workspace]
2026-02-06 00:36:38.684591 | controller | ok
2026-02-06 00:36:38.710289 | 
2026-02-06 00:36:38.710421 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-06 00:36:38.933226 | controller | ok
2026-02-06 00:36:38.949887 | 
2026-02-06 00:36:38.950280 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-06 00:36:51.965338 | controller | Output suppressed because no_log was given
2026-02-06 00:36:52.011426 | 
2026-02-06 00:36:52.011545 | TASK [include_role : prepare-workspace-openshift]
2026-02-06 00:36:52.035630 | controller | skipping: Conditional result was False
2026-02-06 00:36:52.058991 | 
2026-02-06 00:36:52.059110 | PLAY [all:!appliance]
2026-02-06 00:36:52.075583 | 
2026-02-06 00:36:52.075701 | TASK [Run add-build-sshkey role (RSA)]
2026-02-06 00:36:52.095949 | controller | ok
2026-02-06 00:36:52.111317 | 
2026-02-06 00:36:52.111425 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-06 00:36:52.342637 | controller -> localhost | ok
2026-02-06 00:36:52.358542 | 
2026-02-06 00:36:52.358746 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-06 00:36:52.387901 | controller | ok
2026-02-06 00:36:52.415599 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-06 00:36:52.424648 | 
2026-02-06 00:36:52.424743 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-06 00:36:53.032679 | controller -> localhost | Generating public/private rsa key pair.
2026-02-06 00:36:53.032984 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_rsa.
2026-02-06 00:36:53.033103 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_rsa.pub.
2026-02-06 00:36:53.033154 | controller -> localhost | The key fingerprint is:
2026-02-06 00:36:53.033198 | controller -> localhost | SHA256:VVAepoI+IUZs0KH3Oos6O9TRDRxXgTo1JG/q60Xl5DE zuul-build-sshkey
2026-02-06 00:36:53.033242 | controller -> localhost | The key's randomart image is:
2026-02-06 00:36:53.033284 | controller -> localhost | +---[RSA 2048]----+
2026-02-06 00:36:53.033325 | controller -> localhost | |  .+++oooooo=    |
2026-02-06 00:36:53.033366 | controller -> localhost | |   o+o+=   = .   |
2026-02-06 00:36:53.033406 | controller -> localhost | |  ..= BooEo .    |
2026-02-06 00:36:53.033447 | controller -> localhost | |   + Boo=oo      |
2026-02-06 00:36:53.033487 | controller -> localhost | |  . ..=.So       |
2026-02-06 00:36:53.033546 | controller -> localhost | | . .....         |
2026-02-06 00:36:53.033599 | controller -> localhost | |.   o. .         |
2026-02-06 00:36:53.033643 | controller -> localhost | |o  . oo          |
2026-02-06 00:36:53.033685 | controller -> localhost | |o=. oo           |
2026-02-06 00:36:53.033732 | controller -> localhost | +----[SHA256]-----+
2026-02-06 00:36:53.033826 | controller -> localhost | ok: Runtime: 0:00:00.161422
2026-02-06 00:36:53.051376 | 
2026-02-06 00:36:53.051584 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-06 00:36:53.079139 | controller | ok
2026-02-06 00:36:53.093049 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-06 00:36:53.106178 | 
2026-02-06 00:36:53.106276 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-06 00:36:53.121995 | controller | skipping: Conditional result was False
2026-02-06 00:36:53.132480 | 
2026-02-06 00:36:53.132600 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-06 00:36:53.540713 | controller | changed
2026-02-06 00:36:53.549227 | 
2026-02-06 00:36:53.549368 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-06 00:36:53.765553 | controller | ok
2026-02-06 00:36:53.774335 | 
2026-02-06 00:36:53.774485 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-06 00:36:54.367147 | controller | changed
2026-02-06 00:36:54.381554 | 
2026-02-06 00:36:54.381742 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-06 00:36:55.055445 | controller | changed
2026-02-06 00:36:55.064719 | 
2026-02-06 00:36:55.064823 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-06 00:36:55.090909 | controller | skipping: Conditional result was False
2026-02-06 00:36:55.100375 | 
2026-02-06 00:36:55.100479 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-06 00:36:55.495057 | controller -> localhost | changed
2026-02-06 00:36:55.521304 | 
2026-02-06 00:36:55.521481 | TASK [add-build-sshkey : Add back temp key]
2026-02-06 00:36:55.827430 | controller -> localhost | Identity added: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_rsa (zuul-build-sshkey)
2026-02-06 00:36:55.827847 | controller -> localhost | ok: Runtime: 0:00:00.007874
2026-02-06 00:36:55.842862 | 
2026-02-06 00:36:55.843048 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-06 00:36:56.210304 | controller | ok
2026-02-06 00:36:56.220478 | 
2026-02-06 00:36:56.220588 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-06 00:36:56.270405 | controller | skipping: Conditional result was False
2026-02-06 00:36:56.284619 | 
2026-02-06 00:36:56.284750 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-06 00:36:56.321674 | controller | ok
2026-02-06 00:36:56.339675 | 
2026-02-06 00:36:56.339821 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-06 00:36:56.568903 | controller -> localhost | ok
2026-02-06 00:36:56.584346 | 
2026-02-06 00:36:56.584531 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-06 00:36:56.609110 | controller | ok
2026-02-06 00:36:56.626096 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-06 00:36:56.636194 | 
2026-02-06 00:36:56.636315 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-06 00:36:56.927646 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-06 00:36:56.927876 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_ecdsa.
2026-02-06 00:36:56.927905 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_ecdsa.pub.
2026-02-06 00:36:56.927936 | controller -> localhost | The key fingerprint is:
2026-02-06 00:36:56.927956 | controller -> localhost | SHA256:4U0AnhLaXo3tEzbaLQ0+9BecKn/uaWbuRlPNs9vBaOs zuul-build-sshkey
2026-02-06 00:36:56.927975 | controller -> localhost | The key's randomart image is:
2026-02-06 00:36:56.927993 | controller -> localhost | +---[ECDSA 521]---+
2026-02-06 00:36:56.928011 | controller -> localhost | |    . ...        |
2026-02-06 00:36:56.928063 | controller -> localhost | |   o o = . . .   |
2026-02-06 00:36:56.928086 | controller -> localhost | |  . o = X . +  o |
2026-02-06 00:36:56.928104 | controller -> localhost | |   . o O @ . ...o|
2026-02-06 00:36:56.928121 | controller -> localhost | |    . . S * ..o o|
2026-02-06 00:36:56.928138 | controller -> localhost | |         * .oo + |
2026-02-06 00:36:56.928155 | controller -> localhost | |          ..o.. +|
2026-02-06 00:36:56.928171 | controller -> localhost | |           o=o ..|
2026-02-06 00:36:56.928190 | controller -> localhost | |           OBE   |
2026-02-06 00:36:56.928209 | controller -> localhost | +----[SHA256]-----+
2026-02-06 00:36:56.928261 | controller -> localhost | ok: Runtime: 0:00:00.011551
2026-02-06 00:36:56.935963 | 
2026-02-06 00:36:56.936134 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-06 00:36:56.972933 | controller | ok
2026-02-06 00:36:56.981122 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-06 00:36:56.995644 | 
2026-02-06 00:36:56.995799 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-06 00:36:57.021459 | controller | skipping: Conditional result was False
2026-02-06 00:36:57.031805 | 
2026-02-06 00:36:57.031970 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-06 00:36:57.299108 | controller | changed
2026-02-06 00:36:57.305060 | 
2026-02-06 00:36:57.305133 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-06 00:36:57.558849 | controller | ok
2026-02-06 00:36:57.574006 | 
2026-02-06 00:36:57.574242 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-06 00:36:58.215248 | controller | changed
2026-02-06 00:36:58.226238 | 
2026-02-06 00:36:58.226385 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-06 00:36:58.873097 | controller | changed
2026-02-06 00:36:58.888287 | 
2026-02-06 00:36:58.888495 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-06 00:36:58.916220 | controller | skipping: Conditional result was False
2026-02-06 00:36:58.933380 | 
2026-02-06 00:36:58.933587 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-06 00:36:59.208903 | controller -> localhost | changed
2026-02-06 00:36:59.289301 | 
2026-02-06 00:36:59.289485 | TASK [add-build-sshkey : Add back temp key]
2026-02-06 00:36:59.663722 | controller -> localhost | Identity added: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/5af98248e2bd45f89b01441a60728628_id_ecdsa (zuul-build-sshkey)
2026-02-06 00:36:59.664061 | controller -> localhost | ok: Runtime: 0:00:00.016432
2026-02-06 00:36:59.673898 | 
2026-02-06 00:36:59.674059 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-06 00:36:59.895401 | controller | ok
2026-02-06 00:36:59.910551 | 
2026-02-06 00:36:59.910795 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-06 00:36:59.941000 | controller | skipping: Conditional result was False
2026-02-06 00:36:59.971663 | 
2026-02-06 00:36:59.971872 | TASK [include_role : remove-zuul-sshkey]
2026-02-06 00:36:59.998605 | controller | skipping: Conditional result was False
2026-02-06 00:37:00.008852 | 
2026-02-06 00:37:00.008981 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-06 00:37:00.250494 | controller | ok: "logs"
2026-02-06 00:37:00.250920 | controller | ok: All items complete
2026-02-06 00:37:00.250969 | 
2026-02-06 00:37:00.453554 | controller | ok: "artifacts"
2026-02-06 00:37:00.647720 | controller | ok: "docs"
2026-02-06 00:37:00.662725 | 
2026-02-06 00:37:00.662870 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-06 00:37:00.929485 | controller | changed: "logs"
2026-02-06 00:37:01.129844 | controller | changed: "artifacts"
2026-02-06 00:37:01.343870 | controller | changed: "docs"
2026-02-06 00:37:01.409637 | 
2026-02-06 00:37:01.409769 | PLAY RECAP
2026-02-06 00:37:01.409827 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-06 00:37:01.409864 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-06 00:37:01.409890 | 
2026-02-06 00:37:01.522395 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-06 00:37:01.523577 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-06 00:37:02.102159 | 
2026-02-06 00:37:02.102302 | PLAY [all]
2026-02-06 00:37:02.125925 | 
2026-02-06 00:37:02.126117 | TASK [Install binary dependencies]
2026-02-06 00:37:02.217769 | controller | ok
2026-02-06 00:37:02.239092 | 
2026-02-06 00:37:02.239240 | TASK [bindep : Include find tasks]
2026-02-06 00:37:02.271553 | controller | ok
2026-02-06 00:37:02.279881 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-06 00:37:02.287106 | 
2026-02-06 00:37:02.287183 | TASK [bindep : Look for bindep.txt]
2026-02-06 00:37:02.629815 | controller | ok
2026-02-06 00:37:02.644789 | 
2026-02-06 00:37:02.645075 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:37:02.663320 | controller | skipping: Conditional result was False
2026-02-06 00:37:02.679996 | 
2026-02-06 00:37:02.680290 | TASK [bindep : Look for other-requirements.txt]
2026-02-06 00:37:02.891924 | controller | ok
2026-02-06 00:37:02.900347 | 
2026-02-06 00:37:02.900487 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:37:02.926354 | controller | skipping: Conditional result was False
2026-02-06 00:37:02.936116 | 
2026-02-06 00:37:02.936289 | TASK [bindep : Look for bindep fallback file]
2026-02-06 00:37:02.972183 | controller | skipping: Conditional result was False
2026-02-06 00:37:02.980046 | 
2026-02-06 00:37:02.980159 | TASK [bindep : Define bindep_file fact]
2026-02-06 00:37:03.014313 | controller | skipping: Conditional result was False
2026-02-06 00:37:03.021545 | 
2026-02-06 00:37:03.021631 | TASK [bindep : Include bindep tasks]
2026-02-06 00:37:03.045526 | controller | skipping: Conditional result was False
2026-02-06 00:37:03.052473 | 
2026-02-06 00:37:03.052566 | TASK [bindep : Include install tasks]
2026-02-06 00:37:03.086258 | controller | skipping: Conditional result was False
2026-02-06 00:37:03.092770 | 
2026-02-06 00:37:03.092856 | LOOP [bindep : Include package tasks]
2026-02-06 00:37:03.182804 | 
2026-02-06 00:37:03.183047 | TASK [Run test-setup role]
2026-02-06 00:37:03.206389 | controller | ok
2026-02-06 00:37:03.230338 | 
2026-02-06 00:37:03.230492 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-06 00:37:03.453074 | controller | ok
2026-02-06 00:37:03.469329 | 
2026-02-06 00:37:03.469552 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-06 00:37:04.019504 | controller | skipping: Conditional result was False
2026-02-06 00:37:04.049216 | 
2026-02-06 00:37:04.049357 | PLAY RECAP
2026-02-06 00:37:04.049406 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-06 00:37:04.049427 | 
2026-02-06 00:37:04.188819 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-06 00:37:04.189877 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-06 00:37:04.810425 | 
2026-02-06 00:37:04.810575 | PLAY [controller]
2026-02-06 00:37:04.832311 | 
2026-02-06 00:37:04.832466 | TASK [Create the /root directory]
2026-02-06 00:37:05.238520 | controller | ok
2026-02-06 00:37:05.253599 | 
2026-02-06 00:37:05.253820 | TASK [Install glibc-langpack-en]
2026-02-06 00:37:09.222940 | controller | ok: Nothing to do
2026-02-06 00:37:09.231046 | 
2026-02-06 00:37:09.231160 | TASK [Ensure controller directory exists]
2026-02-06 00:37:09.447457 | controller | changed
2026-02-06 00:37:09.456679 | 
2026-02-06 00:37:09.456830 | TASK [Install container runtime]
2026-02-06 00:37:09.500247 | controller | ok
2026-02-06 00:37:09.545049 | 
2026-02-06 00:37:09.545178 | LOOP [ensure-podman : Find distribution installation]
2026-02-06 00:37:09.575697 | controller | ok: "/var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-06 00:37:09.586072 | controller | included: /var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-06 00:37:09.592449 | 
2026-02-06 00:37:09.592521 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-06 00:38:15.108260 | controller | changed
2026-02-06 00:38:15.123311 | 
2026-02-06 00:38:15.123474 | TASK [ensure-podman : Fetch podman version]
2026-02-06 00:38:15.674225 | controller | Client:       Podman Engine
2026-02-06 00:38:15.674303 | controller | Version:      4.6.2
2026-02-06 00:38:15.674336 | controller | API Version:  4.6.2
2026-02-06 00:38:15.674366 | controller | Go Version:   go1.19.12
2026-02-06 00:38:15.674404 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-06 00:38:15.674434 | controller | OS/Arch:      linux/amd64
2026-02-06 00:38:16.179606 | controller | ok: Runtime: 0:00:00.187073
2026-02-06 00:38:16.194527 | 
2026-02-06 00:38:16.194689 | TASK [ensure-podman : Print podman version installed]
2026-02-06 00:38:16.237505 | Podman version: Client:       Podman Engine
2026-02-06 00:38:16.237968 | Version:      4.6.2
2026-02-06 00:38:16.238086 | API Version:  4.6.2
2026-02-06 00:38:16.238152 | Go Version:   go1.19.12
2026-02-06 00:38:16.238195 | Built:        Mon Aug 28 19:38:31 2023
2026-02-06 00:38:16.238240 | OS/Arch:      linux/amd64
2026-02-06 00:38:16.251523 | 
2026-02-06 00:38:16.251668 | TASK [ensure-podman : Validate podman engine]
2026-02-06 00:38:16.806411 | controller | skipping: Conditional result was False
2026-02-06 00:38:16.816723 | 
2026-02-06 00:38:16.816879 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-06 00:38:16.834501 | controller | skipping: Conditional result was False
2026-02-06 00:38:16.864657 | 
2026-02-06 00:38:16.864897 | TASK [Ensure python3.8 is present]
2026-02-06 00:38:16.892082 | controller | skipping: Conditional result was False
2026-02-06 00:38:16.906157 | 
2026-02-06 00:38:16.906316 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-06 00:38:16.933416 | controller | ok
2026-02-06 00:38:16.965076 | 
2026-02-06 00:38:16.965288 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-06 00:38:18.345433 | controller | ok: Nothing to do
2026-02-06 00:38:18.360920 | 
2026-02-06 00:38:18.361140 | TASK [our-ensure-python : Also install python3-devel]
2026-02-06 00:38:31.004699 | controller | changed
2026-02-06 00:38:31.024377 | 
2026-02-06 00:38:31.024574 | TASK [Run ensure-virtualenv role]
2026-02-06 00:38:31.058341 | controller | ok
2026-02-06 00:38:31.079576 | 
2026-02-06 00:38:31.079669 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-06 00:38:31.338352 | controller | /usr/bin/virtualenv
2026-02-06 00:38:31.648554 | controller | ok: Runtime: 0:00:00.005859
2026-02-06 00:38:31.658416 | 
2026-02-06 00:38:31.658594 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-06 00:38:31.698410 | controller | skipping: Conditional result was False
2026-02-06 00:38:31.699105 | controller | ok: All items complete
2026-02-06 00:38:31.699181 | 
2026-02-06 00:38:31.730309 | 
2026-02-06 00:38:31.730520 | TASK [Find the full path of the Python interpreter]
2026-02-06 00:38:31.965021 | controller | /usr/bin/python3
2026-02-06 00:38:32.278913 | controller | ok
2026-02-06 00:38:32.292054 | 
2026-02-06 00:38:32.292281 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-06 00:38:33.191460 | controller | created virtual environment CPython3.11.0.final.0-64 in 469ms
2026-02-06 00:38:33.207909 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-06 00:38:33.207948 | 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:33.207958 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-06 00:38:33.207972 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-06 00:38:33.350920 | controller | changed
2026-02-06 00:38:33.364852 | 
2026-02-06 00:38:33.365083 | TASK [Set selinux package]
2026-02-06 00:38:33.395162 | controller | ok
2026-02-06 00:38:33.407863 | 
2026-02-06 00:38:33.408108 | TASK [Set selinux package (Fedora)]
2026-02-06 00:38:33.471818 | controller | ok
2026-02-06 00:38:33.483596 | 
2026-02-06 00:38:33.483769 | TASK [Install selinux into virtualenv]
2026-02-06 00:38:59.042435 | controller | Collecting selinux-please-lie-to-me
2026-02-06 00:39:11.240057 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-06 00:39:11.547940 | controller | Collecting setuptools<50.0.0
2026-02-06 00:39:11.552686 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-06 00:39:11.587190 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.4 MB/s eta 0:00:00
2026-02-06 00:39:11.671694 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-06 00:39:11.671958 | controller |   Attempting uninstall: setuptools
2026-02-06 00:39:11.674395 | controller |     Found existing installation: setuptools 62.6.0
2026-02-06 00:39:11.734577 | controller |     Uninstalling setuptools-62.6.0:
2026-02-06 00:39:11.742479 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-06 00:39:12.082299 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-06 00:39:23.613463 | controller |
2026-02-06 00:39:23.699206 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-06 00:39:23.699259 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-06 00:39:24.076318 | controller | ok: Runtime: 0:00:50.001450
2026-02-06 00:39:24.082741 | 
2026-02-06 00:39:24.082811 | TASK [Install pytest-forked into virtualenv]
2026-02-06 00:39:33.813549 | controller | Collecting pytest-forked
2026-02-06 00:39:46.057425 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-06 00:39:46.238951 | controller | Collecting py
2026-02-06 00:39:46.244422 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-06 00:39:46.324701 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 1.2 MB/s eta 0:00:00
2026-02-06 00:39:46.479244 | controller | Collecting pytest>=3.10
2026-02-06 00:39:46.484110 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-06 00:39:46.509117 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 17.4 MB/s eta 0:00:00
2026-02-06 00:39:46.558906 | controller | Collecting iniconfig>=1.0.1
2026-02-06 00:39:46.563431 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-06 00:39:46.615646 | controller | Collecting packaging>=22
2026-02-06 00:39:46.619620 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-06 00:39:46.629134 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 10.4 MB/s eta 0:00:00
2026-02-06 00:39:46.668187 | controller | Collecting pluggy<2,>=1.5
2026-02-06 00:39:46.672091 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-06 00:39:46.724472 | controller | Collecting pygments>=2.7.2
2026-02-06 00:39:46.728453 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-06 00:39:46.765202 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 38.6 MB/s eta 0:00:00
2026-02-06 00:39:46.837495 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-06 00:39:47.915169 | 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:47.923707 | controller |
2026-02-06 00:39:47.990716 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-06 00:39:47.990758 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-06 00:39:48.129157 | controller | ok: Runtime: 0:00:23.704871
2026-02-06 00:39:48.180759 | 
2026-02-06 00:39:48.180960 | TASK [Update pip]
2026-02-06 00:39:48.703934 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-06 00:39:58.440404 | controller | Collecting pip
2026-02-06 00:40:10.627618 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-06 00:40:10.684789 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.6 MB/s eta 0:00:00
2026-02-06 00:40:10.751019 | controller | Installing collected packages: pip
2026-02-06 00:40:10.751175 | controller |   Attempting uninstall: pip
2026-02-06 00:40:10.753569 | controller |     Found existing installation: pip 22.2.2
2026-02-06 00:40:10.892181 | controller |     Uninstalling pip-22.2.2:
2026-02-06 00:40:10.907325 | controller |       Successfully uninstalled pip-22.2.2
2026-02-06 00:40:11.730230 | controller | Successfully installed pip-26.0.1
2026-02-06 00:40:12.239954 | controller | ok: Runtime: 0:00:23.400574
2026-02-06 00:40:12.254065 | 
2026-02-06 00:40:12.254239 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-06 00:40:12.488684 | controller | changed
2026-02-06 00:40:12.502595 | 
2026-02-06 00:40:12.502851 | TASK [Install ansible into virtualenv]
2026-02-06 00:40:13.018032 | controller | Processing ./src/github.com/ansible/ansible
2026-02-06 00:40:13.020432 | controller |   Installing build dependencies: started
2026-02-06 00:40:33.921253 | controller |   Installing build dependencies: finished with status 'done'
2026-02-06 00:40:33.922456 | controller |   Getting requirements to build wheel: started
2026-02-06 00:40:34.673421 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-06 00:40:34.674353 | controller |   Preparing metadata (pyproject.toml): started
2026-02-06 00:40:35.131030 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-06 00:40:35.133645 | 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:35.136581 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-06 00:40:35.569217 | controller | ERROR
2026-02-06 00:40:35.570243 | controller | {
2026-02-06 00:40:35.570287 | controller |   "delta": "0:00:22.487062",
2026-02-06 00:40:35.570308 | controller |   "end": "2026-02-06 00:40:35.227563",
2026-02-06 00:40:35.570327 | controller |   "msg": "non-zero return code",
2026-02-06 00:40:35.570358 | controller |   "rc": 1,
2026-02-06 00:40:35.570375 | controller |   "start": "2026-02-06 00:40:12.740501"
2026-02-06 00:40:35.570391 | controller | }
failure
2026-02-06 00:40:35.573359 | 
2026-02-06 00:40:35.573417 | PLAY RECAP
2026-02-06 00:40:35.573469 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-06 00:40:35.573489 | 
2026-02-06 00:40:35.771405 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-06 00:40:35.773575 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-06 00:40:36.415131 | 
2026-02-06 00:40:36.415266 | PLAY [all]
2026-02-06 00:40:36.438960 | 
2026-02-06 00:40:36.439108 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-06 00:40:36.723714 | controller | changed: non-zero return code
2026-02-06 00:40:36.737962 | 
2026-02-06 00:40:36.738197 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-06 00:40:36.766148 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.780265 | 
2026-02-06 00:40:36.780434 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-06 00:40:36.823152 | 
2026-02-06 00:40:36.823434 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-06 00:40:36.865117 | 
2026-02-06 00:40:36.865405 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-06 00:40:36.893294 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.909006 | 
2026-02-06 00:40:36.909215 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-06 00:40:36.952389 | 
2026-02-06 00:40:36.952693 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-06 00:40:36.972897 | controller | skipping: Conditional result was False
2026-02-06 00:40:36.987698 | 
2026-02-06 00:40:36.987853 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-06 00:40:37.005425 | controller | skipping: Conditional result was False
2026-02-06 00:40:37.020260 | 
2026-02-06 00:40:37.020402 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-06 00:40:37.039722 | controller | skipping: Conditional result was False
2026-02-06 00:40:37.078786 | 
2026-02-06 00:40:37.078924 | PLAY RECAP
2026-02-06 00:40:37.078981 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-06 00:40:37.079009 | 
2026-02-06 00:40:37.191887 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-06 00:40:37.192794 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-06 00:40:37.808571 | 
2026-02-06 00:40:37.808722 | PLAY [all:!appliance*]
2026-02-06 00:40:37.832399 | 
2026-02-06 00:40:37.832544 | TASK [unregister the node]
2026-02-06 00:40:38.364192 | controller | skipping: Conditional result was False
2026-02-06 00:40:38.377529 | 
2026-02-06 00:40:38.377769 | TASK [include_role : fetch-output]
2026-02-06 00:40:38.427540 | controller | ok
2026-02-06 00:40:38.472419 | 
2026-02-06 00:40:38.472636 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-06 00:40:38.529145 | controller | skipping: Conditional result was False
2026-02-06 00:40:38.538252 | 
2026-02-06 00:40:38.538381 | TASK [fetch-output : Set log path for single node]
2026-02-06 00:40:38.574374 | controller | ok
2026-02-06 00:40:38.583156 | 
2026-02-06 00:40:38.583329 | LOOP [fetch-output : Ensure local output dirs]
2026-02-06 00:40:39.046962 | controller -> localhost | ok: "/var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/logs"
2026-02-06 00:40:39.313296 | controller -> localhost | changed: "/var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/artifacts"
2026-02-06 00:40:39.542726 | controller -> localhost | changed: "/var/lib/zuul/builds/5af98248e2bd45f89b01441a60728628/work/docs"
2026-02-06 00:40:39.572516 | 
2026-02-06 00:40:39.572747 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-06 00:40:40.227861 | controller | changed:
2026-02-06 00:40:40.228138 | controller | .d..t...... ./
2026-02-06 00:40:40.228188 | controller | cd+++++++++ controller/
2026-02-06 00:40:40.228240 | controller | changed: All items complete
2026-02-06 00:40:40.228274 | 
2026-02-06 00:40:40.699671 | controller | changed: .d..t...... ./
2026-02-06 00:40:41.222791 | controller | changed: .d..t...... ./
2026-02-06 00:40:41.238633 | 
2026-02-06 00:40:41.238743 | TASK [include_role : fetch-output-openshift]
2026-02-06 00:40:41.262956 | controller | skipping: Conditional result was False
2026-02-06 00:40:41.269605 | 
2026-02-06 00:40:41.269686 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-06 00:40:41.312543 | controller | skipping: Conditional result was False
2026-02-06 00:40:41.327038 | controller | skipping: Conditional result was False
2026-02-06 00:40:41.366910 | 
2026-02-06 00:40:41.367044 | PLAY [localhost]
2026-02-06 00:40:41.380269 | 
2026-02-06 00:40:41.380372 | TASK [Run Zuul manifest role]
2026-02-06 00:40:41.400375 | localhost | ok
2026-02-06 00:40:41.417559 | 
2026-02-06 00:40:41.417682 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-06 00:40:41.824242 | localhost | changed
2026-02-06 00:40:41.830225 | 
2026-02-06 00:40:41.830345 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-06 00:40:41.888199 | localhost | ok
2026-02-06 00:40:41.896357 | 
2026-02-06 00:40:41.896433 | TASK [Set zuul-log-path fact]
2026-02-06 00:40:41.926260 | localhost | ok
2026-02-06 00:40:41.940855 | 
2026-02-06 00:40:41.941059 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-06 00:40:41.981918 | localhost | ok
2026-02-06 00:40:41.991554 | 
2026-02-06 00:40:41.991670 | LOOP [Run upload-logs-swift role]
2026-02-06 00:40:42.029741 | localhost | Output suppressed because no_log was given
2026-02-06 00:40:42.081047 | 
2026-02-06 00:40:42.081241 | TASK [Set zuul-log-path fact]
2026-02-06 00:40:42.117652 | localhost | skipping: Conditional result was False
2026-02-06 00:40:42.123403 | 
2026-02-06 00:40:42.123478 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-06 00:40:42.669803 | localhost -> localhost | ok: Runtime: 0:00:00.011687
2026-02-06 00:40:42.707229 | 
2026-02-06 00:40:42.707364 | TASK [upload-logs-swift : Upload logs to swift]