2026-02-05 00:14:24.609251 | Job console starting...
2026-02-05 00:14:24.623951 | Updating repositories
2026-02-05 00:14:24.779557 | Preparing job workspace
2026-02-05 00:14:28.591540 | Running Ansible setup...
2026-02-05 00:14:33.385796 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-05 00:14:34.011090 | 
2026-02-05 00:14:34.011231 | PLAY [localhost]
2026-02-05 00:14:34.020421 | 
2026-02-05 00:14:34.020493 | TASK [Gathering Facts]
2026-02-05 00:14:35.002093 | localhost | ok
2026-02-05 00:14:35.023288 | 
2026-02-05 00:14:35.023487 | TASK [Setup log path fact]
2026-02-05 00:14:35.045749 | localhost | ok
2026-02-05 00:14:35.065462 | 
2026-02-05 00:14:35.065617 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-05 00:14:35.095939 | localhost | ok
2026-02-05 00:14:35.107168 | 
2026-02-05 00:14:35.107297 | TASK [emit-job-header : Print job information]
2026-02-05 00:14:35.147957 | # Job Information
2026-02-05 00:14:35.148146 | Ansible Version: 2.15.12
2026-02-05 00:14:35.148190 | Job: ansible-test-sanity-docker-milestone
2026-02-05 00:14:35.148224 | Pipeline: periodic
2026-02-05 00:14:35.148254 | Executor: ze02.softwarefactory-project.io
2026-02-05 00:14:35.148283 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-05 00:14:35.148316 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/c79/ansible/c79dc0d7b62748b98f8cfa09acca3cc5/
2026-02-05 00:14:35.148346 | Event ID: 9feee7bbbe884a658b69c76d84949d2e
2026-02-05 00:14:35.154238 | 
2026-02-05 00:14:35.154349 | LOOP [emit-job-header : Print node information]
2026-02-05 00:14:35.257029 | localhost | ok:
2026-02-05 00:14:35.257197 | localhost | # Node Information
2026-02-05 00:14:35.257231 | localhost | Inventory Hostname: controller
2026-02-05 00:14:35.257253 | localhost | Hostname: np0005609081
2026-02-05 00:14:35.257273 | localhost | Username: zuul
2026-02-05 00:14:35.257296 | localhost | Distro: Fedora 37
2026-02-05 00:14:35.257315 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-05 00:14:35.257333 | localhost | Region: ca-ymq-1
2026-02-05 00:14:35.257349 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-05 00:14:35.257366 | localhost | Product Name: OpenStack Nova
2026-02-05 00:14:35.257383 | localhost | Interface IP: 162.253.55.110
2026-02-05 00:14:35.277222 | 
2026-02-05 00:14:35.277408 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-05 00:14:35.802917 | localhost -> localhost | changed
2026-02-05 00:14:35.808339 | 
2026-02-05 00:14:35.808429 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-05 00:14:36.748026 | localhost -> localhost | changed
2026-02-05 00:14:36.767455 | 
2026-02-05 00:14:36.767550 | PLAY [all:!appliance*]
2026-02-05 00:14:36.783527 | 
2026-02-05 00:14:36.783595 | TASK [include_role : start-zuul-console]
2026-02-05 00:14:36.802107 | controller | ok
2026-02-05 00:14:36.815533 | 
2026-02-05 00:14:36.815600 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-05 00:14:37.206750 | controller | ok
2026-02-05 00:14:37.229190 | 
2026-02-05 00:14:37.229350 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-05 00:15:08.351941 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-05 00:15:08.362557 | 
2026-02-05 00:15:08.362722 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-05 00:15:08.903904 | controller | skipping: Conditional result was False
2026-02-05 00:15:08.920197 | 
2026-02-05 00:15:08.920346 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-05 00:15:08.961220 | controller | skipping: Conditional result was False
2026-02-05 00:15:08.977054 | 
2026-02-05 00:15:08.977199 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-05 00:15:09.002122 | controller | skipping: Conditional result was False
2026-02-05 00:15:09.012593 | 
2026-02-05 00:15:09.012781 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-05 00:15:09.038857 | controller | skipping: Conditional result was False
2026-02-05 00:15:09.048700 | 
2026-02-05 00:15:09.048863 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-05 00:15:09.074387 | controller | skipping: Conditional result was False
2026-02-05 00:15:09.084611 | 
2026-02-05 00:15:09.084846 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-05 00:15:09.111059 | controller | skipping: Conditional result was False
2026-02-05 00:15:09.131720 | 
2026-02-05 00:15:09.131881 | TASK [Disable Fedora Modular]
2026-02-05 00:15:09.496769 | controller | changed
2026-02-05 00:15:09.511986 | 
2026-02-05 00:15:09.512167 | TASK [Enable EPEL]
2026-02-05 00:15:09.549514 | controller | skipping: Conditional result was False
2026-02-05 00:15:09.563859 | 
2026-02-05 00:15:09.564010 | TASK [Register the RHEL node]
2026-02-05 00:15:10.132404 | 
2026-02-05 00:15:10.132778 | TASK [Show the subscription-manager status]
2026-02-05 00:15:10.702762 | controller | skipping: Conditional result was False
2026-02-05 00:15:10.716482 | 
2026-02-05 00:15:10.716659 | TASK [Enable EPEL on RHEL]
2026-02-05 00:15:11.287362 | controller | skipping: Conditional result was False
2026-02-05 00:15:11.293680 | 
2026-02-05 00:15:11.293750 | TASK [Install git and tox]
2026-02-05 00:15:59.928392 | controller | changed
2026-02-05 00:15:59.937410 | 
2026-02-05 00:15:59.937499 | TASK [include_role : prepare-workspace]
2026-02-05 00:15:59.971469 | controller | ok
2026-02-05 00:16:00.030225 | 
2026-02-05 00:16:00.030337 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-05 00:16:00.291827 | controller | ok
2026-02-05 00:16:00.308752 | 
2026-02-05 00:16:00.308938 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-05 00:16:12.473882 | controller | Output suppressed because no_log was given
2026-02-05 00:16:12.497050 | 
2026-02-05 00:16:12.497194 | TASK [include_role : prepare-workspace-openshift]
2026-02-05 00:16:12.524615 | controller | skipping: Conditional result was False
2026-02-05 00:16:12.557746 | 
2026-02-05 00:16:12.557849 | PLAY [all:!appliance]
2026-02-05 00:16:12.581982 | 
2026-02-05 00:16:12.582118 | TASK [Run add-build-sshkey role (RSA)]
2026-02-05 00:16:12.604443 | controller | ok
2026-02-05 00:16:12.622940 | 
2026-02-05 00:16:12.623040 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-05 00:16:12.953930 | controller -> localhost | ok
2026-02-05 00:16:12.961137 | 
2026-02-05 00:16:12.961213 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-05 00:16:12.984863 | controller | ok
2026-02-05 00:16:13.011162 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-05 00:16:13.022997 | 
2026-02-05 00:16:13.023139 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-05 00:16:13.485392 | controller -> localhost | Generating public/private rsa key pair.
2026-02-05 00:16:13.485597 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_rsa.
2026-02-05 00:16:13.485635 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_rsa.pub.
2026-02-05 00:16:13.485681 | controller -> localhost | The key fingerprint is:
2026-02-05 00:16:13.485716 | controller -> localhost | SHA256:S9MH2zsu2IZFumgeA5ZkY9nFqw7JJQeQSI6/gYst920 zuul-build-sshkey
2026-02-05 00:16:13.485747 | controller -> localhost | The key's randomart image is:
2026-02-05 00:16:13.485772 | controller -> localhost | +---[RSA 2048]----+
2026-02-05 00:16:13.485796 | controller -> localhost | |.o.o   ..        |
2026-02-05 00:16:13.485820 | controller -> localhost | |+ . .o ..        |
2026-02-05 00:16:13.485844 | controller -> localhost | |..  *..  ..      |
2026-02-05 00:16:13.485867 | controller -> localhost | | o +.oo ...+     |
2026-02-05 00:16:13.485888 | controller -> localhost | |. o.+= .Soo o    |
2026-02-05 00:16:13.485921 | controller -> localhost | |.o ++....o.. .   |
2026-02-05 00:16:13.485945 | controller -> localhost | |+ +  oo..*  o    |
2026-02-05 00:16:13.485964 | controller -> localhost | | o . .Eo+ +. .   |
2026-02-05 00:16:13.485985 | controller -> localhost | |    .+o  . ..    |
2026-02-05 00:16:13.486016 | controller -> localhost | +----[SHA256]-----+
2026-02-05 00:16:13.486071 | controller -> localhost | ok: Runtime: 0:00:00.022718
2026-02-05 00:16:13.493604 | 
2026-02-05 00:16:13.493695 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-05 00:16:13.513813 | controller | ok
2026-02-05 00:16:13.524450 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-05 00:16:13.534358 | 
2026-02-05 00:16:13.534458 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-05 00:16:13.548552 | controller | skipping: Conditional result was False
2026-02-05 00:16:13.557308 | 
2026-02-05 00:16:13.557486 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-05 00:16:14.003095 | controller | changed
2026-02-05 00:16:14.016480 | 
2026-02-05 00:16:14.016629 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-05 00:16:14.260326 | controller | ok
2026-02-05 00:16:14.274332 | 
2026-02-05 00:16:14.274522 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-05 00:16:14.943140 | controller | changed
2026-02-05 00:16:14.951897 | 
2026-02-05 00:16:14.951985 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-05 00:16:15.575169 | controller | changed
2026-02-05 00:16:15.591735 | 
2026-02-05 00:16:15.592125 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-05 00:16:15.619821 | controller | skipping: Conditional result was False
2026-02-05 00:16:15.637354 | 
2026-02-05 00:16:15.637576 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-05 00:16:16.024031 | controller -> localhost | changed
2026-02-05 00:16:16.038482 | 
2026-02-05 00:16:16.038616 | TASK [add-build-sshkey : Add back temp key]
2026-02-05 00:16:16.383612 | controller -> localhost | Identity added: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_rsa (zuul-build-sshkey)
2026-02-05 00:16:16.384006 | controller -> localhost | ok: Runtime: 0:00:00.015145
2026-02-05 00:16:16.398547 | 
2026-02-05 00:16:16.398739 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-05 00:16:16.718891 | controller | ok
2026-02-05 00:16:16.735281 | 
2026-02-05 00:16:16.735440 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-05 00:16:16.763028 | controller | skipping: Conditional result was False
2026-02-05 00:16:16.789504 | 
2026-02-05 00:16:16.789711 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-05 00:16:16.823946 | controller | ok
2026-02-05 00:16:16.847810 | 
2026-02-05 00:16:16.848328 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-05 00:16:17.132274 | controller -> localhost | ok
2026-02-05 00:16:17.141884 | 
2026-02-05 00:16:17.141976 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-05 00:16:17.172555 | controller | ok
2026-02-05 00:16:17.186231 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-05 00:16:17.194745 | 
2026-02-05 00:16:17.194847 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-05 00:16:17.515145 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-05 00:16:17.515344 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_ecdsa.
2026-02-05 00:16:17.515375 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_ecdsa.pub.
2026-02-05 00:16:17.515409 | controller -> localhost | The key fingerprint is:
2026-02-05 00:16:17.515437 | controller -> localhost | SHA256:eOoL2UrgiEdjWQ70hqe6WSXG79ktIVYHnvNGBIehLzo zuul-build-sshkey
2026-02-05 00:16:17.515458 | controller -> localhost | The key's randomart image is:
2026-02-05 00:16:17.515477 | controller -> localhost | +---[ECDSA 521]---+
2026-02-05 00:16:17.515495 | controller -> localhost | |  .   o+.        |
2026-02-05 00:16:17.515515 | controller -> localhost | | . o .o..        |
2026-02-05 00:16:17.515534 | controller -> localhost | |  o *. +         |
2026-02-05 00:16:17.515553 | controller -> localhost | | . O .=.o        |
2026-02-05 00:16:17.515570 | controller -> localhost | |  @ +.o=S        |
2026-02-05 00:16:17.515588 | controller -> localhost | |.B Bo+.oo        |
2026-02-05 00:16:17.515605 | controller -> localhost | |+ E.=.oo         |
2026-02-05 00:16:17.515623 | controller -> localhost | | = + *..         |
2026-02-05 00:16:17.515640 | controller -> localhost | |o   + +o.        |
2026-02-05 00:16:17.515658 | controller -> localhost | +----[SHA256]-----+
2026-02-05 00:16:17.515757 | controller -> localhost | ok: Runtime: 0:00:00.016295
2026-02-05 00:16:17.523365 | 
2026-02-05 00:16:17.523438 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-05 00:16:17.573653 | controller | ok
2026-02-05 00:16:17.583433 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-05 00:16:17.592447 | 
2026-02-05 00:16:17.592542 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-05 00:16:17.617563 | controller | skipping: Conditional result was False
2026-02-05 00:16:17.624288 | 
2026-02-05 00:16:17.624364 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-05 00:16:17.928132 | controller | changed
2026-02-05 00:16:17.939258 | 
2026-02-05 00:16:17.939422 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-05 00:16:18.163157 | controller | ok
2026-02-05 00:16:18.179887 | 
2026-02-05 00:16:18.180048 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-05 00:16:18.780531 | controller | changed
2026-02-05 00:16:18.793097 | 
2026-02-05 00:16:18.793245 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-05 00:16:19.426044 | controller | changed
2026-02-05 00:16:19.432234 | 
2026-02-05 00:16:19.432351 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-05 00:16:19.457103 | controller | skipping: Conditional result was False
2026-02-05 00:16:19.470822 | 
2026-02-05 00:16:19.471010 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-05 00:16:19.732032 | controller -> localhost | changed
2026-02-05 00:16:19.758974 | 
2026-02-05 00:16:19.759176 | TASK [add-build-sshkey : Add back temp key]
2026-02-05 00:16:20.073435 | controller -> localhost | Identity added: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/c79dc0d7b62748b98f8cfa09acca3cc5_id_ecdsa (zuul-build-sshkey)
2026-02-05 00:16:20.073698 | controller -> localhost | ok: Runtime: 0:00:00.007540
2026-02-05 00:16:20.080955 | 
2026-02-05 00:16:20.081067 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-05 00:16:20.275065 | controller | ok
2026-02-05 00:16:20.281297 | 
2026-02-05 00:16:20.281387 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-05 00:16:20.305815 | controller | skipping: Conditional result was False
2026-02-05 00:16:20.317438 | 
2026-02-05 00:16:20.317547 | TASK [include_role : remove-zuul-sshkey]
2026-02-05 00:16:20.331518 | controller | skipping: Conditional result was False
2026-02-05 00:16:20.339443 | 
2026-02-05 00:16:20.339566 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-05 00:16:20.561509 | controller | ok: "logs"
2026-02-05 00:16:20.561915 | controller | ok: All items complete
2026-02-05 00:16:20.561960 | 
2026-02-05 00:16:20.755040 | controller | ok: "artifacts"
2026-02-05 00:16:20.945574 | controller | ok: "docs"
2026-02-05 00:16:20.954475 | 
2026-02-05 00:16:20.954594 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-05 00:16:21.198041 | controller | changed: "logs"
2026-02-05 00:16:21.394117 | controller | changed: "artifacts"
2026-02-05 00:16:21.609515 | controller | changed: "docs"
2026-02-05 00:16:21.640267 | 
2026-02-05 00:16:21.640369 | PLAY RECAP
2026-02-05 00:16:21.640415 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-05 00:16:21.640442 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-05 00:16:21.640461 | 
2026-02-05 00:16:21.756314 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-05 00:16:21.757581 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-05 00:16:22.321354 | 
2026-02-05 00:16:22.321474 | PLAY [all]
2026-02-05 00:16:22.344727 | 
2026-02-05 00:16:22.344854 | TASK [Install binary dependencies]
2026-02-05 00:16:22.425128 | controller | ok
2026-02-05 00:16:22.447871 | 
2026-02-05 00:16:22.448010 | TASK [bindep : Include find tasks]
2026-02-05 00:16:22.491651 | controller | ok
2026-02-05 00:16:22.500118 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-05 00:16:22.509068 | 
2026-02-05 00:16:22.509214 | TASK [bindep : Look for bindep.txt]
2026-02-05 00:16:22.899245 | controller | ok
2026-02-05 00:16:22.907659 | 
2026-02-05 00:16:22.907812 | TASK [bindep : Define bindep_file fact]
2026-02-05 00:16:22.934301 | controller | skipping: Conditional result was False
2026-02-05 00:16:22.945025 | 
2026-02-05 00:16:22.945142 | TASK [bindep : Look for other-requirements.txt]
2026-02-05 00:16:23.167495 | controller | ok
2026-02-05 00:16:23.181220 | 
2026-02-05 00:16:23.181370 | TASK [bindep : Define bindep_file fact]
2026-02-05 00:16:23.219611 | controller | skipping: Conditional result was False
2026-02-05 00:16:23.233994 | 
2026-02-05 00:16:23.234137 | TASK [bindep : Look for bindep fallback file]
2026-02-05 00:16:23.261211 | controller | skipping: Conditional result was False
2026-02-05 00:16:23.277761 | 
2026-02-05 00:16:23.277976 | TASK [bindep : Define bindep_file fact]
2026-02-05 00:16:23.306318 | controller | skipping: Conditional result was False
2026-02-05 00:16:23.320832 | 
2026-02-05 00:16:23.320982 | TASK [bindep : Include bindep tasks]
2026-02-05 00:16:23.348244 | controller | skipping: Conditional result was False
2026-02-05 00:16:23.363121 | 
2026-02-05 00:16:23.363269 | TASK [bindep : Include install tasks]
2026-02-05 00:16:23.391978 | controller | skipping: Conditional result was False
2026-02-05 00:16:23.408864 | 
2026-02-05 00:16:23.409034 | LOOP [bindep : Include package tasks]
2026-02-05 00:16:23.498997 | 
2026-02-05 00:16:23.499240 | TASK [Run test-setup role]
2026-02-05 00:16:23.522915 | controller | ok
2026-02-05 00:16:23.547908 | 
2026-02-05 00:16:23.548022 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-05 00:16:23.774618 | controller | ok
2026-02-05 00:16:23.783480 | 
2026-02-05 00:16:23.783600 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-05 00:16:24.326555 | controller | skipping: Conditional result was False
2026-02-05 00:16:24.386023 | 
2026-02-05 00:16:24.386308 | PLAY RECAP
2026-02-05 00:16:24.386404 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-05 00:16:24.386448 | 
2026-02-05 00:16:24.517838 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-05 00:16:24.519657 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-05 00:16:25.154797 | 
2026-02-05 00:16:25.154983 | PLAY [controller]
2026-02-05 00:16:25.176878 | 
2026-02-05 00:16:25.176985 | TASK [Create the /root directory]
2026-02-05 00:16:25.569165 | controller | ok
2026-02-05 00:16:25.577944 | 
2026-02-05 00:16:25.578114 | TASK [Install glibc-langpack-en]
2026-02-05 00:16:29.505659 | controller | ok: Nothing to do
2026-02-05 00:16:29.518311 | 
2026-02-05 00:16:29.518453 | TASK [Ensure controller directory exists]
2026-02-05 00:16:29.761412 | controller | changed
2026-02-05 00:16:29.774760 | 
2026-02-05 00:16:29.774979 | TASK [Install container runtime]
2026-02-05 00:16:29.855615 | controller | ok
2026-02-05 00:16:29.916903 | 
2026-02-05 00:16:29.917055 | LOOP [ensure-podman : Find distribution installation]
2026-02-05 00:16:29.945818 | controller | ok: "/var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-05 00:16:29.958399 | controller | included: /var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-05 00:16:29.964906 | 
2026-02-05 00:16:29.964975 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-05 00:17:35.418319 | controller | changed
2026-02-05 00:17:35.433860 | 
2026-02-05 00:17:35.434008 | TASK [ensure-podman : Fetch podman version]
2026-02-05 00:17:36.008641 | controller | Client:       Podman Engine
2026-02-05 00:17:36.008729 | controller | Version:      4.6.2
2026-02-05 00:17:36.008777 | controller | API Version:  4.6.2
2026-02-05 00:17:36.008819 | controller | Go Version:   go1.19.12
2026-02-05 00:17:36.008871 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-05 00:17:36.008913 | controller | OS/Arch:      linux/amd64
2026-02-05 00:17:36.491608 | controller | ok: Runtime: 0:00:00.220677
2026-02-05 00:17:36.498719 | 
2026-02-05 00:17:36.498798 | TASK [ensure-podman : Print podman version installed]
2026-02-05 00:17:36.538689 | Podman version: Client:       Podman Engine
2026-02-05 00:17:36.538836 | Version:      4.6.2
2026-02-05 00:17:36.538864 | API Version:  4.6.2
2026-02-05 00:17:36.538885 | Go Version:   go1.19.12
2026-02-05 00:17:36.538906 | Built:        Mon Aug 28 19:38:31 2023
2026-02-05 00:17:36.538934 | OS/Arch:      linux/amd64
2026-02-05 00:17:36.544893 | 
2026-02-05 00:17:36.544958 | TASK [ensure-podman : Validate podman engine]
2026-02-05 00:17:37.079810 | controller | skipping: Conditional result was False
2026-02-05 00:17:37.094789 | 
2026-02-05 00:17:37.094962 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-05 00:17:37.121759 | controller | skipping: Conditional result was False
2026-02-05 00:17:37.134648 | 
2026-02-05 00:17:37.134782 | TASK [Ensure python3.8 is present]
2026-02-05 00:17:37.158342 | controller | skipping: Conditional result was False
2026-02-05 00:17:37.165852 | 
2026-02-05 00:17:37.165952 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-05 00:17:37.193911 | controller | ok
2026-02-05 00:17:37.212805 | 
2026-02-05 00:17:37.212879 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-05 00:17:38.770253 | controller | ok: Nothing to do
2026-02-05 00:17:38.777132 | 
2026-02-05 00:17:38.777195 | TASK [our-ensure-python : Also install python3-devel]
2026-02-05 00:17:49.447442 | controller | changed
2026-02-05 00:17:49.473845 | 
2026-02-05 00:17:49.473973 | TASK [Run ensure-virtualenv role]
2026-02-05 00:17:49.497074 | controller | ok
2026-02-05 00:17:49.526474 | 
2026-02-05 00:17:49.526594 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-05 00:17:49.766254 | controller | /usr/bin/virtualenv
2026-02-05 00:17:50.068773 | controller | ok: Runtime: 0:00:00.003260
2026-02-05 00:17:50.080837 | 
2026-02-05 00:17:50.080955 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-05 00:17:50.110392 | controller | skipping: Conditional result was False
2026-02-05 00:17:50.110903 | controller | ok: All items complete
2026-02-05 00:17:50.110969 | 
2026-02-05 00:17:50.136092 | 
2026-02-05 00:17:50.136274 | TASK [Find the full path of the Python interpreter]
2026-02-05 00:17:50.394384 | controller | /usr/bin/python3
2026-02-05 00:17:50.714403 | controller | ok
2026-02-05 00:17:50.727980 | 
2026-02-05 00:17:50.728157 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-05 00:17:51.585689 | controller | created virtual environment CPython3.11.0.final.0-64 in 485ms
2026-02-05 00:17:51.610593 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-05 00:17:51.611226 | 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-05 00:17:51.611765 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-05 00:17:51.611920 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-05 00:17:51.788533 | controller | changed
2026-02-05 00:17:51.799849 | 
2026-02-05 00:17:51.799964 | TASK [Set selinux package]
2026-02-05 00:17:51.829734 | controller | ok
2026-02-05 00:17:51.840573 | 
2026-02-05 00:17:51.840687 | TASK [Set selinux package (Fedora)]
2026-02-05 00:17:51.875595 | controller | ok
2026-02-05 00:17:51.883011 | 
2026-02-05 00:17:51.883083 | TASK [Install selinux into virtualenv]
2026-02-05 00:18:05.403854 | controller | Collecting selinux-please-lie-to-me
2026-02-05 00:18:17.654518 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-05 00:18:17.997145 | controller | Collecting setuptools<50.0.0
2026-02-05 00:18:18.003977 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-05 00:18:18.037497 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.2 MB/s eta 0:00:00
2026-02-05 00:18:18.121622 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-05 00:18:18.121858 | controller |   Attempting uninstall: setuptools
2026-02-05 00:18:18.124871 | controller |     Found existing installation: setuptools 62.6.0
2026-02-05 00:18:18.186604 | controller |     Uninstalling setuptools-62.6.0:
2026-02-05 00:18:18.194977 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-05 00:18:18.550548 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-05 00:18:30.010860 | controller |
2026-02-05 00:18:30.094986 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-05 00:18:30.095083 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-05 00:18:30.446237 | controller | ok: Runtime: 0:00:38.006196
2026-02-05 00:18:30.461505 | 
2026-02-05 00:18:30.461639 | TASK [Install pytest-forked into virtualenv]
2026-02-05 00:18:42.270526 | controller | Collecting pytest-forked
2026-02-05 00:18:54.507324 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-05 00:18:54.553138 | controller | Collecting py
2026-02-05 00:18:54.557060 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-05 00:18:54.576632 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.2 MB/s eta 0:00:00
2026-02-05 00:18:54.683138 | controller | Collecting pytest>=3.10
2026-02-05 00:18:54.687602 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-05 00:18:54.709654 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.4 MB/s eta 0:00:00
2026-02-05 00:18:54.780478 | controller | Collecting iniconfig>=1.0.1
2026-02-05 00:18:54.783617 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-05 00:18:54.831694 | controller | Collecting packaging>=22
2026-02-05 00:18:54.834720 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-05 00:18:54.841842 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 19.6 MB/s eta 0:00:00
2026-02-05 00:18:54.875476 | controller | Collecting pluggy<2,>=1.5
2026-02-05 00:18:54.881096 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-05 00:18:54.938045 | controller | Collecting pygments>=2.7.2
2026-02-05 00:18:54.941351 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-05 00:18:54.969213 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 48.8 MB/s eta 0:00:00
2026-02-05 00:18:55.040621 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-05 00:18:56.108216 | 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-05 00:18:56.117225 | controller |
2026-02-05 00:18:56.189774 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-05 00:18:56.189805 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-05 00:18:56.529043 | controller | ok: Runtime: 0:00:25.487760
2026-02-05 00:18:56.541955 | 
2026-02-05 00:18:56.542099 | TASK [Update pip]
2026-02-05 00:18:57.097097 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-05 00:19:06.908211 | controller | Collecting pip
2026-02-05 00:19:19.091356 | controller |   Downloading pip-26.0-py3-none-any.whl (1.8 MB)
2026-02-05 00:19:19.152174 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.6 MB/s eta 0:00:00
2026-02-05 00:19:19.215992 | controller | Installing collected packages: pip
2026-02-05 00:19:19.216130 | controller |   Attempting uninstall: pip
2026-02-05 00:19:19.218226 | controller |     Found existing installation: pip 22.2.2
2026-02-05 00:19:19.357748 | controller |     Uninstalling pip-22.2.2:
2026-02-05 00:19:19.373700 | controller |       Successfully uninstalled pip-22.2.2
2026-02-05 00:19:20.203260 | controller | Successfully installed pip-26.0
2026-02-05 00:19:20.615530 | controller | ok: Runtime: 0:00:23.480033
2026-02-05 00:19:20.623591 | 
2026-02-05 00:19:20.623697 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-05 00:19:20.854531 | controller | changed
2026-02-05 00:19:20.867217 | 
2026-02-05 00:19:20.867364 | TASK [Install ansible into virtualenv]
2026-02-05 00:19:21.386166 | controller | Processing ./src/github.com/ansible/ansible
2026-02-05 00:19:21.389144 | controller |   Installing build dependencies: started
2026-02-05 00:19:44.300826 | controller |   Installing build dependencies: finished with status 'done'
2026-02-05 00:19:45.031181 | controller |   Getting requirements to build wheel: started
2026-02-05 00:19:45.031275 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-05 00:19:45.031500 | controller |   Preparing metadata (pyproject.toml): started
2026-02-05 00:19:45.509174 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-05 00:19:45.514024 | 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-05 00:19:45.519577 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-05 00:19:45.934343 | controller | ERROR
2026-02-05 00:19:45.934578 | controller | {
2026-02-05 00:19:45.934643 | controller |   "delta": "0:00:24.477353",
2026-02-05 00:19:45.934753 | controller |   "end": "2026-02-05 00:19:45.583002",
2026-02-05 00:19:45.934797 | controller |   "msg": "non-zero return code",
2026-02-05 00:19:45.934851 | controller |   "rc": 1,
2026-02-05 00:19:45.934889 | controller |   "start": "2026-02-05 00:19:21.105649"
2026-02-05 00:19:45.934926 | controller | }
failure
2026-02-05 00:19:45.938176 | 
2026-02-05 00:19:45.938273 | PLAY RECAP
2026-02-05 00:19:45.938356 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-05 00:19:45.938400 | 
2026-02-05 00:19:46.085234 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-05 00:19:46.087271 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-05 00:19:46.655961 | 
2026-02-05 00:19:46.656236 | PLAY [all]
2026-02-05 00:19:46.682592 | 
2026-02-05 00:19:46.683050 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-05 00:19:46.968098 | controller | changed: non-zero return code
2026-02-05 00:19:46.980908 | 
2026-02-05 00:19:46.981079 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-05 00:19:46.999636 | controller | skipping: Conditional result was False
2026-02-05 00:19:47.015180 | 
2026-02-05 00:19:47.015349 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-05 00:19:47.057725 | 
2026-02-05 00:19:47.058034 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-05 00:19:47.100348 | 
2026-02-05 00:19:47.100635 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-05 00:19:47.128268 | controller | skipping: Conditional result was False
2026-02-05 00:19:47.145799 | 
2026-02-05 00:19:47.145951 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-05 00:19:47.186491 | 
2026-02-05 00:19:47.186771 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-05 00:19:47.213562 | controller | skipping: Conditional result was False
2026-02-05 00:19:47.226785 | 
2026-02-05 00:19:47.226933 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-05 00:19:47.254090 | controller | skipping: Conditional result was False
2026-02-05 00:19:47.267654 | 
2026-02-05 00:19:47.267827 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-05 00:19:47.294711 | controller | skipping: Conditional result was False
2026-02-05 00:19:47.343389 | 
2026-02-05 00:19:47.343463 | PLAY RECAP
2026-02-05 00:19:47.343516 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-05 00:19:47.343543 | 
2026-02-05 00:19:47.443129 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-05 00:19:47.444108 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-05 00:19:48.031626 | 
2026-02-05 00:19:48.031763 | PLAY [all:!appliance*]
2026-02-05 00:19:48.053326 | 
2026-02-05 00:19:48.053418 | TASK [unregister the node]
2026-02-05 00:19:48.587413 | controller | skipping: Conditional result was False
2026-02-05 00:19:48.600744 | 
2026-02-05 00:19:48.600906 | TASK [include_role : fetch-output]
2026-02-05 00:19:48.652471 | controller | ok
2026-02-05 00:19:48.691014 | 
2026-02-05 00:19:48.691124 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-05 00:19:48.746986 | controller | skipping: Conditional result was False
2026-02-05 00:19:48.755366 | 
2026-02-05 00:19:48.755459 | TASK [fetch-output : Set log path for single node]
2026-02-05 00:19:48.799561 | controller | ok
2026-02-05 00:19:48.807384 | 
2026-02-05 00:19:48.807480 | LOOP [fetch-output : Ensure local output dirs]
2026-02-05 00:19:49.203034 | controller -> localhost | ok: "/var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/logs"
2026-02-05 00:19:49.427552 | controller -> localhost | changed: "/var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/artifacts"
2026-02-05 00:19:49.649168 | controller -> localhost | changed: "/var/lib/zuul/builds/c79dc0d7b62748b98f8cfa09acca3cc5/work/docs"
2026-02-05 00:19:49.664435 | 
2026-02-05 00:19:49.664544 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-05 00:19:50.319956 | controller | changed:
2026-02-05 00:19:50.320163 | controller | .d..t...... ./
2026-02-05 00:19:50.320194 | controller | cd+++++++++ controller/
2026-02-05 00:19:50.320240 | controller | changed: All items complete
2026-02-05 00:19:50.320269 | 
2026-02-05 00:19:50.855357 | controller | changed: .d..t...... ./
2026-02-05 00:19:51.385877 | controller | changed: .d..t...... ./
2026-02-05 00:19:51.417102 | 
2026-02-05 00:19:51.417328 | TASK [include_role : fetch-output-openshift]
2026-02-05 00:19:51.445270 | controller | skipping: Conditional result was False
2026-02-05 00:19:51.459111 | 
2026-02-05 00:19:51.459264 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-05 00:19:51.505597 | controller | skipping: Conditional result was False
2026-02-05 00:19:51.516757 | controller | skipping: Conditional result was False
2026-02-05 00:19:51.586407 | 
2026-02-05 00:19:51.586550 | PLAY [localhost]
2026-02-05 00:19:51.603595 | 
2026-02-05 00:19:51.603708 | TASK [Run Zuul manifest role]
2026-02-05 00:19:51.624599 | localhost | ok
2026-02-05 00:19:51.645219 | 
2026-02-05 00:19:51.645354 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-05 00:19:52.077116 | localhost | changed
2026-02-05 00:19:52.082078 | 
2026-02-05 00:19:52.082146 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-05 00:19:52.111341 | localhost | ok
2026-02-05 00:19:52.120208 | 
2026-02-05 00:19:52.120284 | TASK [Set zuul-log-path fact]
2026-02-05 00:19:52.140013 | localhost | ok
2026-02-05 00:19:52.154424 | 
2026-02-05 00:19:52.154516 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-05 00:19:52.193743 | localhost | ok
2026-02-05 00:19:52.202877 | 
2026-02-05 00:19:52.202948 | LOOP [Run upload-logs-swift role]
2026-02-05 00:19:52.239471 | localhost | Output suppressed because no_log was given
2026-02-05 00:19:52.263767 | 
2026-02-05 00:19:52.263833 | TASK [Set zuul-log-path fact]
2026-02-05 00:19:52.297848 | localhost | skipping: Conditional result was False
2026-02-05 00:19:52.302889 | 
2026-02-05 00:19:52.302956 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-05 00:19:52.750394 | localhost -> localhost | ok: Runtime: 0:00:00.008597
2026-02-05 00:19:52.798783 | 
2026-02-05 00:19:52.798937 | TASK [upload-logs-swift : Upload logs to swift]