2026-01-07 00:12:49.486352 | Job console starting...
2026-01-07 00:12:49.497274 | Updating repositories
2026-01-07 00:12:49.622953 | Preparing job workspace
2026-01-07 00:12:53.125270 | Running Ansible setup...
2026-01-07 00:12:57.914423 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-07 00:12:58.543675 | 
2026-01-07 00:12:58.543800 | PLAY [localhost]
2026-01-07 00:12:58.553164 | 
2026-01-07 00:12:58.553250 | TASK [Gathering Facts]
2026-01-07 00:12:59.626779 | localhost | ok
2026-01-07 00:12:59.641429 | 
2026-01-07 00:12:59.641547 | TASK [Setup log path fact]
2026-01-07 00:12:59.659823 | localhost | ok
2026-01-07 00:12:59.672918 | 
2026-01-07 00:12:59.672998 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-07 00:12:59.701153 | localhost | ok
2026-01-07 00:12:59.709402 | 
2026-01-07 00:12:59.709481 | TASK [emit-job-header : Print job information]
2026-01-07 00:12:59.748487 | # Job Information
2026-01-07 00:12:59.748685 | Ansible Version: 2.15.12
2026-01-07 00:12:59.748733 | Job: ansible-test-sanity-docker-milestone
2026-01-07 00:12:59.748762 | Pipeline: periodic
2026-01-07 00:12:59.748785 | Executor: ze01.softwarefactory-project.io
2026-01-07 00:12:59.748810 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-07 00:12:59.748837 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/743/ansible/7430ddcc5d324da5abed5b9075b05f03/
2026-01-07 00:12:59.748861 | Event ID: 087827c9b28a45b7af9092d2d6250d5f
2026-01-07 00:12:59.754010 | 
2026-01-07 00:12:59.754105 | LOOP [emit-job-header : Print node information]
2026-01-07 00:12:59.861800 | localhost | ok:
2026-01-07 00:12:59.861966 | localhost | # Node Information
2026-01-07 00:12:59.861995 | localhost | Inventory Hostname: controller
2026-01-07 00:12:59.862031 | localhost | Hostname: np0005576216
2026-01-07 00:12:59.862071 | localhost | Username: zuul
2026-01-07 00:12:59.862096 | localhost | Distro: Fedora 37
2026-01-07 00:12:59.862114 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-07 00:12:59.862133 | localhost | Region: ca-ymq-1
2026-01-07 00:12:59.862150 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-07 00:12:59.862166 | localhost | Product Name: OpenStack Nova
2026-01-07 00:12:59.862182 | localhost | Interface IP: 162.253.55.186
2026-01-07 00:12:59.887963 | 
2026-01-07 00:12:59.888294 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-07 00:13:00.282647 | localhost -> localhost | changed
2026-01-07 00:13:00.291721 | 
2026-01-07 00:13:00.291834 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-07 00:13:01.201349 | localhost -> localhost | changed
2026-01-07 00:13:01.222799 | 
2026-01-07 00:13:01.222937 | PLAY [all:!appliance*]
2026-01-07 00:13:01.240965 | 
2026-01-07 00:13:01.241128 | TASK [include_role : start-zuul-console]
2026-01-07 00:13:01.260328 | controller | ok
2026-01-07 00:13:01.275547 | 
2026-01-07 00:13:01.275668 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-07 00:13:01.676435 | controller | ok
2026-01-07 00:13:01.687562 | 
2026-01-07 00:13:01.687650 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-07 00:13:02.705635 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-07 00:13:02.719929 | 
2026-01-07 00:13:02.720111 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-07 00:13:03.263706 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.270528 | 
2026-01-07 00:13:03.270625 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-07 00:13:03.294980 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.303196 | 
2026-01-07 00:13:03.303302 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-07 00:13:03.328090 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.335155 | 
2026-01-07 00:13:03.335246 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-07 00:13:03.348746 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.355669 | 
2026-01-07 00:13:03.355784 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-07 00:13:03.369801 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.379095 | 
2026-01-07 00:13:03.379216 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-07 00:13:03.402874 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.416187 | 
2026-01-07 00:13:03.416322 | TASK [Disable Fedora Modular]
2026-01-07 00:13:03.676246 | controller | changed
2026-01-07 00:13:03.684612 | 
2026-01-07 00:13:03.684706 | TASK [Enable EPEL]
2026-01-07 00:13:03.710879 | controller | skipping: Conditional result was False
2026-01-07 00:13:03.721648 | 
2026-01-07 00:13:03.721760 | TASK [Register the RHEL node]
2026-01-07 00:13:04.278325 | 
2026-01-07 00:13:04.278546 | TASK [Show the subscription-manager status]
2026-01-07 00:13:04.878600 | controller | skipping: Conditional result was False
2026-01-07 00:13:04.894106 | 
2026-01-07 00:13:04.894249 | TASK [Enable EPEL on RHEL]
2026-01-07 00:13:05.452360 | controller | skipping: Conditional result was False
2026-01-07 00:13:05.466229 | 
2026-01-07 00:13:05.466402 | TASK [Install git and tox]
2026-01-07 00:14:24.671705 | controller | changed
2026-01-07 00:14:24.689659 | 
2026-01-07 00:14:24.689820 | TASK [include_role : prepare-workspace]
2026-01-07 00:14:24.722795 | controller | ok
2026-01-07 00:14:24.745360 | 
2026-01-07 00:14:24.745460 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-07 00:14:24.997682 | controller | ok
2026-01-07 00:14:25.011815 | 
2026-01-07 00:14:25.011924 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-07 00:14:37.284226 | controller | Output suppressed because no_log was given
2026-01-07 00:14:37.322130 | 
2026-01-07 00:14:37.322244 | TASK [include_role : prepare-workspace-openshift]
2026-01-07 00:14:37.340115 | controller | skipping: Conditional result was False
2026-01-07 00:14:37.365594 | 
2026-01-07 00:14:37.365673 | PLAY [all:!appliance]
2026-01-07 00:14:37.382782 | 
2026-01-07 00:14:37.382873 | TASK [Run add-build-sshkey role (RSA)]
2026-01-07 00:14:37.412957 | controller | ok
2026-01-07 00:14:37.430370 | 
2026-01-07 00:14:37.430481 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-07 00:14:37.709203 | controller -> localhost | ok
2026-01-07 00:14:37.719572 | 
2026-01-07 00:14:37.719670 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-07 00:14:37.753727 | controller | ok
2026-01-07 00:14:37.768547 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-07 00:14:37.786996 | 
2026-01-07 00:14:37.787410 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-07 00:14:38.293722 | controller -> localhost | Generating public/private rsa key pair.
2026-01-07 00:14:38.294166 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_rsa.
2026-01-07 00:14:38.294250 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_rsa.pub.
2026-01-07 00:14:38.294315 | controller -> localhost | The key fingerprint is:
2026-01-07 00:14:38.294362 | controller -> localhost | SHA256:TgMM26UNvkgq6tK3/TDMlbBHeyMHPdsiuORIB/6OZ98 zuul-build-sshkey
2026-01-07 00:14:38.294403 | controller -> localhost | The key's randomart image is:
2026-01-07 00:14:38.294446 | controller -> localhost | +---[RSA 2048]----+
2026-01-07 00:14:38.294531 | controller -> localhost | |    . . .        |
2026-01-07 00:14:38.294582 | controller -> localhost | |     * = .       |
2026-01-07 00:14:38.294625 | controller -> localhost | |    + B + o      |
2026-01-07 00:14:38.294665 | controller -> localhost | |   + o B + +     |
2026-01-07 00:14:38.294704 | controller -> localhost | |. . + * S * .    |
2026-01-07 00:14:38.294760 | controller -> localhost | |.. . O * * o     |
2026-01-07 00:14:38.294812 | controller -> localhost | |..  . O .        |
2026-01-07 00:14:38.294853 | controller -> localhost | |o . .+oo .       |
2026-01-07 00:14:38.294896 | controller -> localhost | |.. .o+ooo E      |
2026-01-07 00:14:38.294944 | controller -> localhost | +----[SHA256]-----+
2026-01-07 00:14:38.295076 | controller -> localhost | ok: Runtime: 0:00:00.097000
2026-01-07 00:14:38.311115 | 
2026-01-07 00:14:38.311269 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-07 00:14:38.338161 | controller | ok
2026-01-07 00:14:38.352714 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-07 00:14:38.367326 | 
2026-01-07 00:14:38.367453 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-07 00:14:38.383355 | controller | skipping: Conditional result was False
2026-01-07 00:14:38.394043 | 
2026-01-07 00:14:38.394152 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-07 00:14:38.825626 | controller | changed
2026-01-07 00:14:38.854444 | 
2026-01-07 00:14:38.854568 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-07 00:14:39.087346 | controller | ok
2026-01-07 00:14:39.101197 | 
2026-01-07 00:14:39.101337 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-07 00:14:39.731539 | controller | changed
2026-01-07 00:14:39.748870 | 
2026-01-07 00:14:39.749226 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-07 00:14:40.380516 | controller | changed
2026-01-07 00:14:40.388093 | 
2026-01-07 00:14:40.388179 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-07 00:14:40.413979 | controller | skipping: Conditional result was False
2026-01-07 00:14:40.422909 | 
2026-01-07 00:14:40.422997 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-07 00:14:40.886187 | controller -> localhost | changed
2026-01-07 00:14:40.906986 | 
2026-01-07 00:14:40.907143 | TASK [add-build-sshkey : Add back temp key]
2026-01-07 00:14:41.191457 | controller -> localhost | Identity added: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_rsa (zuul-build-sshkey)
2026-01-07 00:14:41.191699 | controller -> localhost | ok: Runtime: 0:00:00.009815
2026-01-07 00:14:41.201866 | 
2026-01-07 00:14:41.201982 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-07 00:14:41.558000 | controller | ok
2026-01-07 00:14:41.566154 | 
2026-01-07 00:14:41.566236 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-07 00:14:41.602097 | controller | skipping: Conditional result was False
2026-01-07 00:14:41.620900 | 
2026-01-07 00:14:41.621110 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-07 00:14:41.649431 | controller | ok
2026-01-07 00:14:41.675974 | 
2026-01-07 00:14:41.676175 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-07 00:14:41.924572 | controller -> localhost | ok
2026-01-07 00:14:41.931405 | 
2026-01-07 00:14:41.931509 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-07 00:14:41.981905 | controller | ok
2026-01-07 00:14:41.997309 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-07 00:14:42.005486 | 
2026-01-07 00:14:42.005578 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-07 00:14:42.297263 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-07 00:14:42.297446 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_ecdsa.
2026-01-07 00:14:42.297473 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_ecdsa.pub.
2026-01-07 00:14:42.297502 | controller -> localhost | The key fingerprint is:
2026-01-07 00:14:42.297522 | controller -> localhost | SHA256:aZWhszvVYPd9D3jrZ3Zxvm8m65YxagprTlxpe/JahnQ zuul-build-sshkey
2026-01-07 00:14:42.297542 | controller -> localhost | The key's randomart image is:
2026-01-07 00:14:42.297560 | controller -> localhost | +---[ECDSA 521]---+
2026-01-07 00:14:42.297578 | controller -> localhost | |          .      |
2026-01-07 00:14:42.297595 | controller -> localhost | |         . o     |
2026-01-07 00:14:42.297612 | controller -> localhost | |        o = .    |
2026-01-07 00:14:42.297628 | controller -> localhost | |         * = o . |
2026-01-07 00:14:42.297644 | controller -> localhost | |        S * E + o|
2026-01-07 00:14:42.297661 | controller -> localhost | |       o * + .o++|
2026-01-07 00:14:42.297677 | controller -> localhost | |        * + +..=+|
2026-01-07 00:14:42.297692 | controller -> localhost | |       ..+ *o.+ O|
2026-01-07 00:14:42.297709 | controller -> localhost | |       oo o+.o+X=|
2026-01-07 00:14:42.297725 | controller -> localhost | +----[SHA256]-----+
2026-01-07 00:14:42.297769 | controller -> localhost | ok: Runtime: 0:00:00.007736
2026-01-07 00:14:42.306889 | 
2026-01-07 00:14:42.306966 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-07 00:14:42.329064 | controller | ok
2026-01-07 00:14:42.338332 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-07 00:14:42.349797 | 
2026-01-07 00:14:42.349882 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-07 00:14:42.374856 | controller | skipping: Conditional result was False
2026-01-07 00:14:42.383411 | 
2026-01-07 00:14:42.383511 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-07 00:14:42.650542 | controller | changed
2026-01-07 00:14:42.658708 | 
2026-01-07 00:14:42.658825 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-07 00:14:42.880695 | controller | ok
2026-01-07 00:14:42.894664 | 
2026-01-07 00:14:42.894807 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-07 00:14:43.515123 | controller | changed
2026-01-07 00:14:43.524289 | 
2026-01-07 00:14:43.524400 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-07 00:14:44.145880 | controller | changed
2026-01-07 00:14:44.158879 | 
2026-01-07 00:14:44.159073 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-07 00:14:44.175509 | controller | skipping: Conditional result was False
2026-01-07 00:14:44.191275 | 
2026-01-07 00:14:44.191452 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-07 00:14:44.444071 | controller -> localhost | changed
2026-01-07 00:14:44.508341 | 
2026-01-07 00:14:44.508480 | TASK [add-build-sshkey : Add back temp key]
2026-01-07 00:14:44.839490 | controller -> localhost | Identity added: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/7430ddcc5d324da5abed5b9075b05f03_id_ecdsa (zuul-build-sshkey)
2026-01-07 00:14:44.839814 | controller -> localhost | ok: Runtime: 0:00:00.007284
2026-01-07 00:14:44.849724 | 
2026-01-07 00:14:44.849819 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-07 00:14:45.060055 | controller | ok
2026-01-07 00:14:45.074910 | 
2026-01-07 00:14:45.075356 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-07 00:14:45.114107 | controller | skipping: Conditional result was False
2026-01-07 00:14:45.133502 | 
2026-01-07 00:14:45.133631 | TASK [include_role : remove-zuul-sshkey]
2026-01-07 00:14:45.150833 | controller | skipping: Conditional result was False
2026-01-07 00:14:45.160397 | 
2026-01-07 00:14:45.160510 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-07 00:14:45.398318 | controller | ok: "logs"
2026-01-07 00:14:45.398834 | controller | ok: All items complete
2026-01-07 00:14:45.398929 | 
2026-01-07 00:14:45.595889 | controller | ok: "artifacts"
2026-01-07 00:14:45.789952 | controller | ok: "docs"
2026-01-07 00:14:45.808411 | 
2026-01-07 00:14:45.808540 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-07 00:14:46.028683 | controller | changed: "logs"
2026-01-07 00:14:46.229548 | controller | changed: "artifacts"
2026-01-07 00:14:46.418824 | controller | changed: "docs"
2026-01-07 00:14:46.474230 | 
2026-01-07 00:14:46.474359 | PLAY RECAP
2026-01-07 00:14:46.474418 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-07 00:14:46.474454 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-07 00:14:46.474485 | 
2026-01-07 00:14:46.588843 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-07 00:14:46.590664 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-07 00:14:47.224586 | 
2026-01-07 00:14:47.224717 | PLAY [all]
2026-01-07 00:14:47.247690 | 
2026-01-07 00:14:47.247824 | TASK [Install binary dependencies]
2026-01-07 00:14:47.310039 | controller | ok
2026-01-07 00:14:47.331053 | 
2026-01-07 00:14:47.331184 | TASK [bindep : Include find tasks]
2026-01-07 00:14:47.361377 | controller | ok
2026-01-07 00:14:47.369754 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-07 00:14:47.376869 | 
2026-01-07 00:14:47.376946 | TASK [bindep : Look for bindep.txt]
2026-01-07 00:14:47.762609 | controller | ok
2026-01-07 00:14:47.777182 | 
2026-01-07 00:14:47.777392 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:14:47.806190 | controller | skipping: Conditional result was False
2026-01-07 00:14:47.821652 | 
2026-01-07 00:14:47.821885 | TASK [bindep : Look for other-requirements.txt]
2026-01-07 00:14:48.037213 | controller | ok
2026-01-07 00:14:48.051043 | 
2026-01-07 00:14:48.051252 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:14:48.089282 | controller | skipping: Conditional result was False
2026-01-07 00:14:48.103321 | 
2026-01-07 00:14:48.103472 | TASK [bindep : Look for bindep fallback file]
2026-01-07 00:14:48.141082 | controller | skipping: Conditional result was False
2026-01-07 00:14:48.156181 | 
2026-01-07 00:14:48.156324 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:14:48.184195 | controller | skipping: Conditional result was False
2026-01-07 00:14:48.193469 | 
2026-01-07 00:14:48.193548 | TASK [bindep : Include bindep tasks]
2026-01-07 00:14:48.217773 | controller | skipping: Conditional result was False
2026-01-07 00:14:48.225589 | 
2026-01-07 00:14:48.225656 | TASK [bindep : Include install tasks]
2026-01-07 00:14:48.249707 | controller | skipping: Conditional result was False
2026-01-07 00:14:48.255699 | 
2026-01-07 00:14:48.255762 | LOOP [bindep : Include package tasks]
2026-01-07 00:14:48.311523 | 
2026-01-07 00:14:48.311676 | TASK [Run test-setup role]
2026-01-07 00:14:48.332041 | controller | ok
2026-01-07 00:14:48.348319 | 
2026-01-07 00:14:48.348390 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-07 00:14:48.551427 | controller | ok
2026-01-07 00:14:48.557433 | 
2026-01-07 00:14:48.557498 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-07 00:14:49.091182 | controller | skipping: Conditional result was False
2026-01-07 00:14:49.128410 | 
2026-01-07 00:14:49.128515 | PLAY RECAP
2026-01-07 00:14:49.128570 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-07 00:14:49.128599 | 
2026-01-07 00:14:49.266320 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-07 00:14:49.267178 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-07 00:14:49.883539 | 
2026-01-07 00:14:49.883668 | PLAY [controller]
2026-01-07 00:14:49.904169 | 
2026-01-07 00:14:49.904267 | TASK [Create the /root directory]
2026-01-07 00:14:50.324720 | controller | ok
2026-01-07 00:14:50.338313 | 
2026-01-07 00:14:50.338487 | TASK [Install glibc-langpack-en]
2026-01-07 00:14:54.260733 | controller | ok: Nothing to do
2026-01-07 00:14:54.273939 | 
2026-01-07 00:14:54.274270 | TASK [Ensure controller directory exists]
2026-01-07 00:14:54.492712 | controller | changed
2026-01-07 00:14:54.501870 | 
2026-01-07 00:14:54.501971 | TASK [Install container runtime]
2026-01-07 00:14:54.548231 | controller | ok
2026-01-07 00:14:54.609334 | 
2026-01-07 00:14:54.609472 | LOOP [ensure-podman : Find distribution installation]
2026-01-07 00:14:54.651208 | controller | ok: "/var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-07 00:14:54.664814 | controller | included: /var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-07 00:14:54.671217 | 
2026-01-07 00:14:54.671288 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-07 00:15:59.107531 | controller | changed
2026-01-07 00:15:59.125617 | 
2026-01-07 00:15:59.125788 | TASK [ensure-podman : Fetch podman version]
2026-01-07 00:15:59.715776 | controller | Client:       Podman Engine
2026-01-07 00:15:59.715864 | controller | Version:      4.6.2
2026-01-07 00:15:59.715909 | controller | API Version:  4.6.2
2026-01-07 00:15:59.715952 | controller | Go Version:   go1.19.12
2026-01-07 00:15:59.716004 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-07 00:15:59.716047 | controller | OS/Arch:      linux/amd64
2026-01-07 00:16:00.198961 | controller | ok: Runtime: 0:00:00.209404
2026-01-07 00:16:00.207453 | 
2026-01-07 00:16:00.207550 | TASK [ensure-podman : Print podman version installed]
2026-01-07 00:16:00.244147 | Podman version: Client:       Podman Engine
2026-01-07 00:16:00.244300 | Version:      4.6.2
2026-01-07 00:16:00.244329 | API Version:  4.6.2
2026-01-07 00:16:00.244349 | Go Version:   go1.19.12
2026-01-07 00:16:00.244367 | Built:        Mon Aug 28 19:38:31 2023
2026-01-07 00:16:00.244388 | OS/Arch:      linux/amd64
2026-01-07 00:16:00.249823 | 
2026-01-07 00:16:00.249887 | TASK [ensure-podman : Validate podman engine]
2026-01-07 00:16:00.781493 | controller | skipping: Conditional result was False
2026-01-07 00:16:00.788366 | 
2026-01-07 00:16:00.788433 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-07 00:16:00.811998 | controller | skipping: Conditional result was False
2026-01-07 00:16:00.823419 | 
2026-01-07 00:16:00.823482 | TASK [Ensure python3.8 is present]
2026-01-07 00:16:00.847292 | controller | skipping: Conditional result was False
2026-01-07 00:16:00.852841 | 
2026-01-07 00:16:00.852900 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-07 00:16:00.872457 | controller | ok
2026-01-07 00:16:00.891993 | 
2026-01-07 00:16:00.892080 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-07 00:16:02.385578 | controller | ok: Nothing to do
2026-01-07 00:16:02.397759 | 
2026-01-07 00:16:02.397891 | TASK [our-ensure-python : Also install python3-devel]
2026-01-07 00:16:12.877699 | controller | changed
2026-01-07 00:16:12.903319 | 
2026-01-07 00:16:12.903474 | TASK [Run ensure-virtualenv role]
2026-01-07 00:16:12.927783 | controller | ok
2026-01-07 00:16:12.957469 | 
2026-01-07 00:16:12.957614 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-07 00:16:13.185956 | controller | /usr/bin/virtualenv
2026-01-07 00:16:13.493700 | controller | ok: Runtime: 0:00:00.005033
2026-01-07 00:16:13.509284 | 
2026-01-07 00:16:13.509452 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-07 00:16:13.546371 | controller | skipping: Conditional result was False
2026-01-07 00:16:13.546841 | controller | ok: All items complete
2026-01-07 00:16:13.546903 | 
2026-01-07 00:16:13.574093 | 
2026-01-07 00:16:13.574315 | TASK [Find the full path of the Python interpreter]
2026-01-07 00:16:13.829948 | controller | /usr/bin/python3
2026-01-07 00:16:14.145394 | controller | ok
2026-01-07 00:16:14.155003 | 
2026-01-07 00:16:14.155138 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-07 00:16:15.154727 | controller | created virtual environment CPython3.11.0.final.0-64 in 518ms
2026-01-07 00:16:15.177036 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-07 00:16:15.177052 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2026-01-07 00:16:15.177061 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-07 00:16:15.177073 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-07 00:16:15.217311 | controller | changed
2026-01-07 00:16:15.223538 | 
2026-01-07 00:16:15.223611 | TASK [Set selinux package]
2026-01-07 00:16:15.253631 | controller | ok
2026-01-07 00:16:15.259752 | 
2026-01-07 00:16:15.259856 | TASK [Set selinux package (Fedora)]
2026-01-07 00:16:15.294965 | controller | ok
2026-01-07 00:16:15.304700 | 
2026-01-07 00:16:15.304827 | TASK [Install selinux into virtualenv]
2026-01-07 00:16:28.793630 | controller | Collecting selinux-please-lie-to-me
2026-01-07 00:16:41.047219 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-07 00:16:41.359242 | controller | Collecting setuptools<50.0.0
2026-01-07 00:16:41.364408 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-07 00:16:41.401053 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.3 MB/s eta 0:00:00
2026-01-07 00:16:41.481335 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-07 00:16:41.481559 | controller |   Attempting uninstall: setuptools
2026-01-07 00:16:41.484019 | controller |     Found existing installation: setuptools 62.6.0
2026-01-07 00:16:41.543201 | controller |     Uninstalling setuptools-62.6.0:
2026-01-07 00:16:41.551250 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-07 00:16:41.902858 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-07 00:16:53.423853 | controller |
2026-01-07 00:16:53.508974 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-07 00:16:53.509012 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-07 00:16:53.874728 | controller | ok: Runtime: 0:00:37.988275
2026-01-07 00:16:53.887306 | 
2026-01-07 00:16:53.887433 | TASK [Install pytest-forked into virtualenv]
2026-01-07 00:17:05.665524 | controller | Collecting pytest-forked
2026-01-07 00:17:15.928923 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-07 00:17:15.964751 | controller | Collecting py
2026-01-07 00:17:15.969022 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-07 00:17:15.992778 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.7 MB/s eta 0:00:00
2026-01-07 00:17:16.095413 | controller | Collecting pytest>=3.10
2026-01-07 00:17:16.099488 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-07 00:17:16.114857 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.5 MB/s eta 0:00:00
2026-01-07 00:17:16.150527 | controller | Collecting iniconfig>=1.0.1
2026-01-07 00:17:16.154607 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-07 00:17:16.198980 | controller | Collecting packaging>=22
2026-01-07 00:17:16.202923 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-07 00:17:16.209027 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 15.7 MB/s eta 0:00:00
2026-01-07 00:17:16.240523 | controller | Collecting pluggy<2,>=1.5
2026-01-07 00:17:16.244437 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-07 00:17:16.288380 | controller | Collecting pygments>=2.7.2
2026-01-07 00:17:16.291682 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-07 00:17:16.315238 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 58.1 MB/s eta 0:00:00
2026-01-07 00:17:16.382767 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-07 00:17:17.387811 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-01-07 00:17:17.397336 | controller |
2026-01-07 00:17:17.463229 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-07 00:17:17.463291 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-07 00:17:17.946290 | controller | ok: Runtime: 0:00:23.362767
2026-01-07 00:17:17.952170 | 
2026-01-07 00:17:17.952232 | TASK [Update pip]
2026-01-07 00:17:18.471621 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-07 00:17:30.873320 | controller | Collecting pip
2026-01-07 00:17:43.195746 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-07 00:17:43.243449 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 41.3 MB/s eta 0:00:00
2026-01-07 00:17:43.309411 | controller | Installing collected packages: pip
2026-01-07 00:17:43.309574 | controller |   Attempting uninstall: pip
2026-01-07 00:17:43.311686 | controller |     Found existing installation: pip 22.2.2
2026-01-07 00:17:43.449786 | controller |     Uninstalling pip-22.2.2:
2026-01-07 00:17:43.464414 | controller |       Successfully uninstalled pip-22.2.2
2026-01-07 00:17:44.243515 | controller | Successfully installed pip-25.3
2026-01-07 00:17:44.517936 | controller | ok: Runtime: 0:00:26.129687
2026-01-07 00:17:44.532408 | 
2026-01-07 00:17:44.532580 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-07 00:17:44.757453 | controller | changed
2026-01-07 00:17:44.770570 | 
2026-01-07 00:17:44.770716 | TASK [Install ansible into virtualenv]
2026-01-07 00:17:45.277017 | controller | Processing ./src/github.com/ansible/ansible
2026-01-07 00:17:45.280392 | controller |   Installing build dependencies: started
2026-01-07 00:18:08.180062 | controller |   Installing build dependencies: finished with status 'done'
2026-01-07 00:18:08.180626 | controller |   Getting requirements to build wheel: started
2026-01-07 00:18:08.923138 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-07 00:18:08.924583 | controller |   Preparing metadata (pyproject.toml): started
2026-01-07 00:18:09.385886 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-07 00:18:09.391689 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while.
2026-01-07 00:18:09.396347 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-07 00:18:09.834431 | controller | ERROR
2026-01-07 00:18:09.834690 | controller | {
2026-01-07 00:18:09.834746 | controller |   "delta": "0:00:24.457660",
2026-01-07 00:18:09.834789 | controller |   "end": "2026-01-07 00:18:09.457991",
2026-01-07 00:18:09.834827 | controller |   "msg": "non-zero return code",
2026-01-07 00:18:09.834877 | controller |   "rc": 1,
2026-01-07 00:18:09.834904 | controller |   "start": "2026-01-07 00:17:45.000331"
2026-01-07 00:18:09.834929 | controller | }
failure
2026-01-07 00:18:09.837043 | 
2026-01-07 00:18:09.837125 | PLAY RECAP
2026-01-07 00:18:09.837188 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-07 00:18:09.837218 | 
2026-01-07 00:18:09.975453 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-07 00:18:09.976447 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-07 00:18:10.657967 | 
2026-01-07 00:18:10.658118 | PLAY [all]
2026-01-07 00:18:10.682559 | 
2026-01-07 00:18:10.682687 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-07 00:18:10.897840 | controller | changed: non-zero return code
2026-01-07 00:18:10.905474 | 
2026-01-07 00:18:10.905616 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-07 00:18:10.930418 | controller | skipping: Conditional result was False
2026-01-07 00:18:10.936461 | 
2026-01-07 00:18:10.936537 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-07 00:18:10.956959 | 
2026-01-07 00:18:10.957132 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-07 00:18:10.976788 | 
2026-01-07 00:18:10.976949 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-07 00:18:10.990428 | controller | skipping: Conditional result was False
2026-01-07 00:18:10.997227 | 
2026-01-07 00:18:10.997318 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-07 00:18:11.019323 | 
2026-01-07 00:18:11.019492 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-07 00:18:11.033302 | controller | skipping: Conditional result was False
2026-01-07 00:18:11.040335 | 
2026-01-07 00:18:11.040437 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-07 00:18:11.054491 | controller | skipping: Conditional result was False
2026-01-07 00:18:11.062046 | 
2026-01-07 00:18:11.062144 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-07 00:18:11.075537 | controller | skipping: Conditional result was False
2026-01-07 00:18:11.104260 | 
2026-01-07 00:18:11.104355 | PLAY RECAP
2026-01-07 00:18:11.104396 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-07 00:18:11.104417 | 
2026-01-07 00:18:11.206743 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-07 00:18:11.208067 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-07 00:18:11.771348 | 
2026-01-07 00:18:11.771462 | PLAY [all:!appliance*]
2026-01-07 00:18:11.803864 | 
2026-01-07 00:18:11.803976 | TASK [unregister the node]
2026-01-07 00:18:12.334630 | controller | skipping: Conditional result was False
2026-01-07 00:18:12.348168 | 
2026-01-07 00:18:12.348360 | TASK [include_role : fetch-output]
2026-01-07 00:18:12.403702 | controller | ok
2026-01-07 00:18:12.443492 | 
2026-01-07 00:18:12.443626 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-07 00:18:12.489144 | controller | skipping: Conditional result was False
2026-01-07 00:18:12.498055 | 
2026-01-07 00:18:12.498159 | TASK [fetch-output : Set log path for single node]
2026-01-07 00:18:12.530930 | controller | ok
2026-01-07 00:18:12.539120 | 
2026-01-07 00:18:12.539267 | LOOP [fetch-output : Ensure local output dirs]
2026-01-07 00:18:12.937527 | controller -> localhost | ok: "/var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/logs"
2026-01-07 00:18:13.176377 | controller -> localhost | changed: "/var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/artifacts"
2026-01-07 00:18:13.419881 | controller -> localhost | changed: "/var/lib/zuul/builds/7430ddcc5d324da5abed5b9075b05f03/work/docs"
2026-01-07 00:18:13.438470 | 
2026-01-07 00:18:13.438723 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-07 00:18:14.092850 | controller | changed:
2026-01-07 00:18:14.093306 | controller | .d..t...... ./
2026-01-07 00:18:14.093357 | controller | cd+++++++++ controller/
2026-01-07 00:18:14.093406 | controller | changed: All items complete
2026-01-07 00:18:14.093436 | 
2026-01-07 00:18:14.546204 | controller | changed: .d..t...... ./
2026-01-07 00:18:14.983647 | controller | changed: .d..t...... ./
2026-01-07 00:18:15.007703 | 
2026-01-07 00:18:15.008554 | TASK [include_role : fetch-output-openshift]
2026-01-07 00:18:15.035692 | controller | skipping: Conditional result was False
2026-01-07 00:18:15.043686 | 
2026-01-07 00:18:15.043876 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-07 00:18:15.078554 | controller | skipping: Conditional result was False
2026-01-07 00:18:15.089332 | controller | skipping: Conditional result was False
2026-01-07 00:18:15.143674 | 
2026-01-07 00:18:15.143792 | PLAY [localhost]
2026-01-07 00:18:15.164841 | 
2026-01-07 00:18:15.165081 | TASK [Run Zuul manifest role]
2026-01-07 00:18:15.186416 | localhost | ok
2026-01-07 00:18:15.200633 | 
2026-01-07 00:18:15.200720 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-07 00:18:15.575055 | localhost | changed
2026-01-07 00:18:15.579709 | 
2026-01-07 00:18:15.579768 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-07 00:18:15.609569 | localhost | ok
2026-01-07 00:18:15.617754 | 
2026-01-07 00:18:15.617814 | TASK [Set zuul-log-path fact]
2026-01-07 00:18:15.635947 | localhost | ok
2026-01-07 00:18:15.649890 | 
2026-01-07 00:18:15.649979 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-07 00:18:15.689894 | localhost | ok
2026-01-07 00:18:15.697862 | 
2026-01-07 00:18:15.698010 | LOOP [Run upload-logs-swift role]
2026-01-07 00:18:15.742662 | localhost | Output suppressed because no_log was given
2026-01-07 00:18:15.769902 | 
2026-01-07 00:18:15.770009 | TASK [Set zuul-log-path fact]
2026-01-07 00:18:15.804622 | localhost | skipping: Conditional result was False
2026-01-07 00:18:15.810100 | 
2026-01-07 00:18:15.810169 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-07 00:18:16.222359 | localhost -> localhost | ok: Runtime: 0:00:00.009265
2026-01-07 00:18:16.237982 | 
2026-01-07 00:18:16.238180 | TASK [upload-logs-swift : Upload logs to swift]