2026-01-03 00:20:49.870169 | Job console starting...
2026-01-03 00:20:49.957546 | Updating repositories
2026-01-03 00:20:50.116642 | Preparing job workspace
2026-01-03 00:20:53.841469 | Running Ansible setup...
2026-01-03 00:21:01.547544 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-03 00:21:02.149461 | 
2026-01-03 00:21:02.149608 | PLAY [localhost]
2026-01-03 00:21:02.158376 | 
2026-01-03 00:21:02.158453 | TASK [Gathering Facts]
2026-01-03 00:21:03.260650 | localhost | ok
2026-01-03 00:21:03.305758 | 
2026-01-03 00:21:03.305930 | TASK [Setup log path fact]
2026-01-03 00:21:03.328957 | localhost | ok
2026-01-03 00:21:03.345863 | 
2026-01-03 00:21:03.345972 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-03 00:21:03.377177 | localhost | ok
2026-01-03 00:21:03.387964 | 
2026-01-03 00:21:03.388077 | TASK [emit-job-header : Print job information]
2026-01-03 00:21:03.464156 | # Job Information
2026-01-03 00:21:03.464563 | Ansible Version: 2.15.12
2026-01-03 00:21:03.464617 | Job: ansible-test-sanity-docker-devel
2026-01-03 00:21:03.464715 | Pipeline: periodic
2026-01-03 00:21:03.464801 | Executor: ze01.softwarefactory-project.io
2026-01-03 00:21:03.464841 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-03 00:21:03.464872 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/847/ansible/84796b5a779f4955b82a9baa3cc079b2/
2026-01-03 00:21:03.464899 | Event ID: 84f60a54a6bb4d9ab16f9cfd1e63d8f4
2026-01-03 00:21:03.471619 | 
2026-01-03 00:21:03.471745 | LOOP [emit-job-header : Print node information]
2026-01-03 00:21:03.603283 | localhost | ok:
2026-01-03 00:21:03.603646 | localhost | # Node Information
2026-01-03 00:21:03.603685 | localhost | Inventory Hostname: controller
2026-01-03 00:21:03.603707 | localhost | Hostname: np0005573542
2026-01-03 00:21:03.603729 | localhost | Username: zuul
2026-01-03 00:21:03.603756 | localhost | Distro: Fedora 37
2026-01-03 00:21:03.603777 | localhost | Provider: ansible-vexxhost-ams1
2026-01-03 00:21:03.603797 | localhost | Region: ams1
2026-01-03 00:21:03.603817 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-03 00:21:03.603836 | localhost | Product Name: OpenStack Nova
2026-01-03 00:21:03.603855 | localhost | Interface IP: 38.129.16.168
2026-01-03 00:21:03.622239 | 
2026-01-03 00:21:03.622361 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-03 00:21:04.136291 | localhost -> localhost | changed
2026-01-03 00:21:04.147096 | 
2026-01-03 00:21:04.147280 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-03 00:21:05.182713 | localhost -> localhost | changed
2026-01-03 00:21:05.207536 | 
2026-01-03 00:21:05.207611 | PLAY [all:!appliance*]
2026-01-03 00:21:05.224462 | 
2026-01-03 00:21:05.224540 | TASK [include_role : start-zuul-console]
2026-01-03 00:21:05.246655 | controller | ok
2026-01-03 00:21:05.261974 | 
2026-01-03 00:21:05.262080 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-03 00:21:06.269122 | controller | ok
2026-01-03 00:21:06.283114 | 
2026-01-03 00:21:06.283220 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-03 00:21:08.616688 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-03 00:21:08.623127 | 
2026-01-03 00:21:08.623203 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-03 00:21:08.984224 | controller | skipping: Conditional result was False
2026-01-03 00:21:08.991778 | 
2026-01-03 00:21:08.991949 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-03 00:21:09.020038 | controller | skipping: Conditional result was False
2026-01-03 00:21:09.032594 | 
2026-01-03 00:21:09.032735 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-03 00:21:09.057878 | controller | skipping: Conditional result was False
2026-01-03 00:21:09.065133 | 
2026-01-03 00:21:09.065231 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-03 00:21:09.089665 | controller | skipping: Conditional result was False
2026-01-03 00:21:09.096571 | 
2026-01-03 00:21:09.096655 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-03 00:21:09.131656 | controller | skipping: Conditional result was False
2026-01-03 00:21:09.140066 | 
2026-01-03 00:21:09.140167 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-03 00:21:09.164669 | controller | skipping: Conditional result was False
2026-01-03 00:21:09.180475 | 
2026-01-03 00:21:09.180614 | TASK [Disable Fedora Modular]
2026-01-03 00:21:10.333513 | controller | changed
2026-01-03 00:21:10.339917 | 
2026-01-03 00:21:10.339998 | TASK [Enable EPEL]
2026-01-03 00:21:10.364826 | controller | skipping: Conditional result was False
2026-01-03 00:21:10.382475 | 
2026-01-03 00:21:10.382609 | TASK [Register the RHEL node]
2026-01-03 00:21:10.796010 | 
2026-01-03 00:21:10.796297 | TASK [Show the subscription-manager status]
2026-01-03 00:21:11.173547 | controller | skipping: Conditional result was False
2026-01-03 00:21:11.188164 | 
2026-01-03 00:21:11.188321 | TASK [Enable EPEL on RHEL]
2026-01-03 00:21:11.582939 | controller | skipping: Conditional result was False
2026-01-03 00:21:11.592576 | 
2026-01-03 00:21:11.592778 | TASK [Install git and tox]
2026-01-03 00:23:16.288997 | controller | changed
2026-01-03 00:23:16.303153 | 
2026-01-03 00:23:16.303316 | TASK [include_role : prepare-workspace]
2026-01-03 00:23:16.354195 | controller | ok
2026-01-03 00:23:16.435053 | 
2026-01-03 00:23:16.435220 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-03 00:23:17.252113 | controller | ok
2026-01-03 00:23:17.271933 | 
2026-01-03 00:23:17.272096 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-03 00:23:33.392452 | controller | Output suppressed because no_log was given
2026-01-03 00:23:33.420430 | 
2026-01-03 00:23:33.420620 | TASK [include_role : prepare-workspace-openshift]
2026-01-03 00:23:33.446650 | controller | skipping: Conditional result was False
2026-01-03 00:23:33.515327 | 
2026-01-03 00:23:33.515413 | PLAY [all:!appliance]
2026-01-03 00:23:33.534712 | 
2026-01-03 00:23:33.534804 | TASK [Run add-build-sshkey role (RSA)]
2026-01-03 00:23:33.568079 | controller | ok
2026-01-03 00:23:33.596419 | 
2026-01-03 00:23:33.596548 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-03 00:23:33.837195 | controller -> localhost | ok
2026-01-03 00:23:33.851362 | 
2026-01-03 00:23:33.851500 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-03 00:23:33.882910 | controller | ok
2026-01-03 00:23:33.939213 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-03 00:23:33.953491 | 
2026-01-03 00:23:33.953627 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-03 00:23:34.452744 | controller -> localhost | Generating public/private rsa key pair.
2026-01-03 00:23:34.452985 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_rsa.
2026-01-03 00:23:34.453079 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_rsa.pub.
2026-01-03 00:23:34.453147 | controller -> localhost | The key fingerprint is:
2026-01-03 00:23:34.453187 | controller -> localhost | SHA256:PYn4nYRSkLJub050AFLp/HMSh/VP9tp3vzXK4q9bl9M zuul-build-sshkey
2026-01-03 00:23:34.453222 | controller -> localhost | The key's randomart image is:
2026-01-03 00:23:34.453256 | controller -> localhost | +---[RSA 2048]----+
2026-01-03 00:23:34.453287 | controller -> localhost | |  ..o...         |
2026-01-03 00:23:34.453318 | controller -> localhost | |   .o....        |
2026-01-03 00:23:34.453347 | controller -> localhost | |   o o.o..       |
2026-01-03 00:23:34.453377 | controller -> localhost | |    + o+.+..o    |
2026-01-03 00:23:34.453407 | controller -> localhost | |   . .+oS =+ .   |
2026-01-03 00:23:34.453450 | controller -> localhost | |    o.++.o o. . o|
2026-01-03 00:23:34.453489 | controller -> localhost | |   . ..+. o  + =E|
2026-01-03 00:23:34.453525 | controller -> localhost | |     .o    .+ + *|
2026-01-03 00:23:34.453557 | controller -> localhost | |     o.   .+=+ o=|
2026-01-03 00:23:34.453590 | controller -> localhost | +----[SHA256]-----+
2026-01-03 00:23:34.453666 | controller -> localhost | ok: Runtime: 0:00:00.056799
2026-01-03 00:23:34.463568 | 
2026-01-03 00:23:34.463658 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-03 00:23:34.496171 | controller | ok
2026-01-03 00:23:34.510942 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-03 00:23:34.522851 | 
2026-01-03 00:23:34.522933 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-03 00:23:34.547565 | controller | skipping: Conditional result was False
2026-01-03 00:23:34.556072 | 
2026-01-03 00:23:34.556161 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-03 00:23:35.625555 | controller | changed
2026-01-03 00:23:35.636923 | 
2026-01-03 00:23:35.637009 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-03 00:23:36.260806 | controller | ok
2026-01-03 00:23:36.274773 | 
2026-01-03 00:23:36.274939 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-03 00:23:39.259916 | controller | changed
2026-01-03 00:23:39.266805 | 
2026-01-03 00:23:39.266950 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-03 00:23:42.208579 | controller | changed
2026-01-03 00:23:42.215655 | 
2026-01-03 00:23:42.215753 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-03 00:23:42.241936 | controller | skipping: Conditional result was False
2026-01-03 00:23:42.251920 | 
2026-01-03 00:23:42.252088 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-03 00:23:42.710776 | controller -> localhost | changed
2026-01-03 00:23:42.722630 | 
2026-01-03 00:23:42.722703 | TASK [add-build-sshkey : Add back temp key]
2026-01-03 00:23:42.991090 | controller -> localhost | Identity added: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_rsa (zuul-build-sshkey)
2026-01-03 00:23:42.991345 | controller -> localhost | ok: Runtime: 0:00:00.013250
2026-01-03 00:23:43.001341 | 
2026-01-03 00:23:43.001489 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-03 00:23:43.913831 | controller | ok
2026-01-03 00:23:43.921831 | 
2026-01-03 00:23:43.921922 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-03 00:23:43.958162 | controller | skipping: Conditional result was False
2026-01-03 00:23:43.970507 | 
2026-01-03 00:23:43.970596 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-03 00:23:44.000267 | controller | ok
2026-01-03 00:23:44.018723 | 
2026-01-03 00:23:44.018854 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-03 00:23:44.269114 | controller -> localhost | ok
2026-01-03 00:23:44.287133 | 
2026-01-03 00:23:44.287272 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-03 00:23:44.318864 | controller | ok
2026-01-03 00:23:44.330412 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-03 00:23:44.336989 | 
2026-01-03 00:23:44.337096 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-03 00:23:44.599346 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-03 00:23:44.599734 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_ecdsa.
2026-01-03 00:23:44.599798 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_ecdsa.pub.
2026-01-03 00:23:44.599858 | controller -> localhost | The key fingerprint is:
2026-01-03 00:23:44.599901 | controller -> localhost | SHA256:LGC7I5g0ELtcR22vXjslvAvkBRncAWiv6cwQ7lDeszo zuul-build-sshkey
2026-01-03 00:23:44.599942 | controller -> localhost | The key's randomart image is:
2026-01-03 00:23:44.599983 | controller -> localhost | +---[ECDSA 521]---+
2026-01-03 00:23:44.600086 | controller -> localhost | |.    .+oo..      |
2026-01-03 00:23:44.600135 | controller -> localhost | | o  .o +o.       |
2026-01-03 00:23:44.600175 | controller -> localhost | |o  .+.oo.        |
2026-01-03 00:23:44.600213 | controller -> localhost | |o..+.o o..       |
2026-01-03 00:23:44.600278 | controller -> localhost | |.++ + +.S.       |
2026-01-03 00:23:44.600320 | controller -> localhost | |.+.+ *oo.+ .     |
2026-01-03 00:23:44.600378 | controller -> localhost | |o + B +o. =      |
2026-01-03 00:23:44.600417 | controller -> localhost | |   E * ..+       |
2026-01-03 00:23:44.600455 | controller -> localhost | |   .o    .o      |
2026-01-03 00:23:44.600492 | controller -> localhost | +----[SHA256]-----+
2026-01-03 00:23:44.600592 | controller -> localhost | ok: Runtime: 0:00:00.013240
2026-01-03 00:23:44.615939 | 
2026-01-03 00:23:44.616137 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-03 00:23:44.679138 | controller | ok
2026-01-03 00:23:44.692437 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-03 00:23:44.706614 | 
2026-01-03 00:23:44.706735 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-03 00:23:44.735797 | controller | skipping: Conditional result was False
2026-01-03 00:23:44.744209 | 
2026-01-03 00:23:44.744342 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-03 00:23:45.638338 | controller | changed
2026-01-03 00:23:45.707169 | 
2026-01-03 00:23:45.707324 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-03 00:23:46.367746 | controller | ok
2026-01-03 00:23:46.380717 | 
2026-01-03 00:23:46.380861 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-03 00:23:49.407320 | controller | changed
2026-01-03 00:23:49.413149 | 
2026-01-03 00:23:49.413218 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-03 00:23:52.387847 | controller | changed
2026-01-03 00:23:52.401417 | 
2026-01-03 00:23:52.401583 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-03 00:23:52.428486 | controller | skipping: Conditional result was False
2026-01-03 00:23:52.442699 | 
2026-01-03 00:23:52.442891 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-03 00:23:52.744738 | controller -> localhost | changed
2026-01-03 00:23:52.765480 | 
2026-01-03 00:23:52.765638 | TASK [add-build-sshkey : Add back temp key]
2026-01-03 00:23:53.066575 | controller -> localhost | Identity added: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/84796b5a779f4955b82a9baa3cc079b2_id_ecdsa (zuul-build-sshkey)
2026-01-03 00:23:53.066866 | controller -> localhost | ok: Runtime: 0:00:00.013507
2026-01-03 00:23:53.076716 | 
2026-01-03 00:23:53.076810 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-03 00:23:53.840739 | controller | ok
2026-01-03 00:23:53.855839 | 
2026-01-03 00:23:53.856008 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-03 00:23:53.891159 | controller | skipping: Conditional result was False
2026-01-03 00:23:53.907425 | 
2026-01-03 00:23:53.907559 | TASK [include_role : remove-zuul-sshkey]
2026-01-03 00:23:53.933099 | controller | skipping: Conditional result was False
2026-01-03 00:23:53.942601 | 
2026-01-03 00:23:53.942729 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-03 00:23:54.585274 | controller | ok: "logs"
2026-01-03 00:23:54.585517 | controller | ok: All items complete
2026-01-03 00:23:54.585562 | 
2026-01-03 00:23:55.204854 | controller | ok: "artifacts"
2026-01-03 00:23:55.784915 | controller | ok: "docs"
2026-01-03 00:23:55.800623 | 
2026-01-03 00:23:55.800823 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-03 00:23:56.455545 | controller | changed: "logs"
2026-01-03 00:23:57.081458 | controller | changed: "artifacts"
2026-01-03 00:23:57.676201 | controller | changed: "docs"
2026-01-03 00:23:57.714999 | 
2026-01-03 00:23:57.715142 | PLAY RECAP
2026-01-03 00:23:57.715195 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-03 00:23:57.715224 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-03 00:23:57.715244 | 
2026-01-03 00:23:57.839299 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-03 00:23:57.840947 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-03 00:23:58.522431 | 
2026-01-03 00:23:58.522552 | PLAY [all]
2026-01-03 00:23:58.544828 | 
2026-01-03 00:23:58.544951 | TASK [Install binary dependencies]
2026-01-03 00:23:58.617767 | controller | ok
2026-01-03 00:23:58.640187 | 
2026-01-03 00:23:58.640310 | TASK [bindep : Include find tasks]
2026-01-03 00:23:58.670290 | controller | ok
2026-01-03 00:23:58.680743 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-03 00:23:58.686834 | 
2026-01-03 00:23:58.686901 | TASK [bindep : Look for bindep.txt]
2026-01-03 00:23:59.615567 | controller | ok
2026-01-03 00:23:59.627877 | 
2026-01-03 00:23:59.628087 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:23:59.655459 | controller | skipping: Conditional result was False
2026-01-03 00:23:59.669341 | 
2026-01-03 00:23:59.669536 | TASK [bindep : Look for other-requirements.txt]
2026-01-03 00:24:00.313267 | controller | ok
2026-01-03 00:24:00.333903 | 
2026-01-03 00:24:00.334219 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:24:00.374324 | controller | skipping: Conditional result was False
2026-01-03 00:24:00.386766 | 
2026-01-03 00:24:00.386950 | TASK [bindep : Look for bindep fallback file]
2026-01-03 00:24:00.428437 | controller | skipping: Conditional result was False
2026-01-03 00:24:00.439095 | 
2026-01-03 00:24:00.439309 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:24:00.466984 | controller | skipping: Conditional result was False
2026-01-03 00:24:00.474910 | 
2026-01-03 00:24:00.475010 | TASK [bindep : Include bindep tasks]
2026-01-03 00:24:00.509798 | controller | skipping: Conditional result was False
2026-01-03 00:24:00.518343 | 
2026-01-03 00:24:00.518435 | TASK [bindep : Include install tasks]
2026-01-03 00:24:00.543669 | controller | skipping: Conditional result was False
2026-01-03 00:24:00.552120 | 
2026-01-03 00:24:00.552214 | LOOP [bindep : Include package tasks]
2026-01-03 00:24:00.613210 | 
2026-01-03 00:24:00.613524 | TASK [Run test-setup role]
2026-01-03 00:24:00.635927 | controller | ok
2026-01-03 00:24:00.660626 | 
2026-01-03 00:24:00.660745 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-03 00:24:01.377349 | controller | ok
2026-01-03 00:24:01.393860 | 
2026-01-03 00:24:01.394076 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-03 00:24:01.771009 | controller | skipping: Conditional result was False
2026-01-03 00:24:01.826640 | 
2026-01-03 00:24:01.826764 | PLAY RECAP
2026-01-03 00:24:01.826887 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-03 00:24:01.826976 | 
2026-01-03 00:24:01.935313 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-03 00:24:01.936164 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-03 00:24:02.562702 | 
2026-01-03 00:24:02.562835 | PLAY [controller]
2026-01-03 00:24:02.583765 | 
2026-01-03 00:24:02.583890 | TASK [Create the /root directory]
2026-01-03 00:24:03.576461 | controller | ok
2026-01-03 00:24:03.583617 | 
2026-01-03 00:24:03.583728 | TASK [Install glibc-langpack-en]
2026-01-03 00:24:11.149428 | controller | ok: Nothing to do
2026-01-03 00:24:11.155557 | 
2026-01-03 00:24:11.155623 | TASK [Ensure controller directory exists]
2026-01-03 00:24:11.958799 | controller | changed
2026-01-03 00:24:11.970800 | 
2026-01-03 00:24:11.970935 | TASK [Install container runtime]
2026-01-03 00:24:12.051426 | controller | ok
2026-01-03 00:24:12.113482 | 
2026-01-03 00:24:12.113650 | LOOP [ensure-podman : Find distribution installation]
2026-01-03 00:24:12.143137 | controller | ok: "/var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-03 00:24:12.163444 | controller | included: /var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-03 00:24:12.176855 | 
2026-01-03 00:24:12.177091 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-03 00:26:06.939334 | controller | changed
2026-01-03 00:26:06.955679 | 
2026-01-03 00:26:06.955829 | TASK [ensure-podman : Fetch podman version]
2026-01-03 00:26:08.108008 | controller | Client:       Podman Engine
2026-01-03 00:26:08.142474 | controller | Version:      4.6.2
2026-01-03 00:26:08.142530 | controller | API Version:  4.6.2
2026-01-03 00:26:08.142539 | controller | Go Version:   go1.19.12
2026-01-03 00:26:08.142562 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-03 00:26:08.142570 | controller | OS/Arch:      linux/amd64
2026-01-03 00:26:08.336707 | controller | ok: Runtime: 0:00:00.249418
2026-01-03 00:26:08.350340 | 
2026-01-03 00:26:08.350491 | TASK [ensure-podman : Print podman version installed]
2026-01-03 00:26:08.390853 | Podman version: Client:       Podman Engine
2026-01-03 00:26:08.391405 | Version:      4.6.2
2026-01-03 00:26:08.391529 | API Version:  4.6.2
2026-01-03 00:26:08.391580 | Go Version:   go1.19.12
2026-01-03 00:26:08.391680 | Built:        Mon Aug 28 19:38:31 2023
2026-01-03 00:26:08.391724 | OS/Arch:      linux/amd64
2026-01-03 00:26:08.407956 | 
2026-01-03 00:26:08.408177 | TASK [ensure-podman : Validate podman engine]
2026-01-03 00:26:08.769772 | controller | skipping: Conditional result was False
2026-01-03 00:26:08.784827 | 
2026-01-03 00:26:08.784990 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-03 00:26:08.812457 | controller | skipping: Conditional result was False
2026-01-03 00:26:08.838499 | 
2026-01-03 00:26:08.838667 | TASK [Ensure python3.8 is present]
2026-01-03 00:26:08.866716 | controller | skipping: Conditional result was False
2026-01-03 00:26:08.885859 | 
2026-01-03 00:26:08.886169 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-03 00:26:08.913476 | controller | ok
2026-01-03 00:26:08.948967 | 
2026-01-03 00:26:08.949168 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-03 00:26:12.427761 | controller | ok: Nothing to do
2026-01-03 00:26:12.434485 | 
2026-01-03 00:26:12.434596 | TASK [our-ensure-python : Also install python3-devel]
2026-01-03 00:26:27.033545 | controller | changed
2026-01-03 00:26:27.049286 | 
2026-01-03 00:26:27.049422 | TASK [Run ensure-virtualenv role]
2026-01-03 00:26:27.071230 | controller | ok
2026-01-03 00:26:27.098726 | 
2026-01-03 00:26:27.098856 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-03 00:26:27.884224 | controller | /usr/bin/virtualenv
2026-01-03 00:26:28.490474 | controller | ok: Runtime: 0:00:00.006631
2026-01-03 00:26:28.502582 | 
2026-01-03 00:26:28.502743 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-03 00:26:28.537264 | controller | skipping: Conditional result was False
2026-01-03 00:26:28.537745 | controller | ok: All items complete
2026-01-03 00:26:28.537799 | 
2026-01-03 00:26:28.558339 | 
2026-01-03 00:26:28.558574 | TASK [Find the full path of the Python interpreter]
2026-01-03 00:26:29.347037 | controller | /usr/bin/python3
2026-01-03 00:26:29.926645 | controller | ok
2026-01-03 00:26:29.937334 | 
2026-01-03 00:26:29.937433 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-03 00:26:31.878260 | controller | created virtual environment CPython3.11.0.final.0-64 in 959ms
2026-01-03 00:26:31.929708 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-03 00:26:31.929747 | 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-03 00:26:31.929761 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-03 00:26:31.929783 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-03 00:26:32.325344 | controller | changed
2026-01-03 00:26:32.332213 | 
2026-01-03 00:26:32.332304 | TASK [Set selinux package]
2026-01-03 00:26:32.362829 | controller | ok
2026-01-03 00:26:32.368338 | 
2026-01-03 00:26:32.368421 | TASK [Set selinux package (Fedora)]
2026-01-03 00:26:32.398587 | controller | ok
2026-01-03 00:26:32.404077 | 
2026-01-03 00:26:32.404161 | TASK [Install selinux into virtualenv]
2026-01-03 00:26:35.628338 | controller | Collecting selinux-please-lie-to-me
2026-01-03 00:26:35.691126 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-03 00:26:36.164417 | controller | Collecting setuptools<50.0.0
2026-01-03 00:26:36.169361 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-03 00:26:36.223366 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.7 MB/s eta 0:00:00
2026-01-03 00:26:36.345341 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-03 00:26:36.345523 | controller |   Attempting uninstall: setuptools
2026-01-03 00:26:36.349103 | controller |     Found existing installation: setuptools 62.6.0
2026-01-03 00:26:36.441676 | controller |     Uninstalling setuptools-62.6.0:
2026-01-03 00:26:36.456123 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-03 00:26:37.150043 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-03 00:26:37.351284 | controller |
2026-01-03 00:26:37.623500 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-03 00:26:37.623550 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-03 00:26:37.787209 | controller | ok: Runtime: 0:00:04.395713
2026-01-03 00:26:37.797217 | 
2026-01-03 00:26:37.797317 | TASK [Install pytest-forked into virtualenv]
2026-01-03 00:26:39.201786 | controller | Collecting pytest-forked
2026-01-03 00:26:39.260512 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-03 00:26:39.322824 | controller | Collecting py
2026-01-03 00:26:39.327779 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-03 00:26:39.359950 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.2 MB/s eta 0:00:00
2026-01-03 00:26:39.596818 | controller | Collecting pytest>=3.10
2026-01-03 00:26:39.600221 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-03 00:26:39.628538 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 14.7 MB/s eta 0:00:00
2026-01-03 00:26:39.700818 | controller | Collecting iniconfig>=1.0.1
2026-01-03 00:26:39.705867 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-03 00:26:39.771641 | controller | Collecting packaging>=22
2026-01-03 00:26:39.776489 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-03 00:26:39.784516 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.2 MB/s eta 0:00:00
2026-01-03 00:26:39.836943 | controller | Collecting pluggy<2,>=1.5
2026-01-03 00:26:39.842292 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-03 00:26:39.909053 | controller | Collecting pygments>=2.7.2
2026-01-03 00:26:39.913592 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-03 00:26:39.940477 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.9 MB/s eta 0:00:00
2026-01-03 00:26:40.052471 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-03 00:26:42.383565 | 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-03 00:26:42.396113 | controller |
2026-01-03 00:26:42.619581 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-03 00:26:42.619633 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-03 00:26:43.185798 | controller | ok: Runtime: 0:00:04.076278
2026-01-03 00:26:43.198528 | 
2026-01-03 00:26:43.198681 | TASK [Update pip]
2026-01-03 00:26:44.602390 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-03 00:26:44.861602 | controller | Collecting pip
2026-01-03 00:26:44.934679 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-03 00:26:45.024361 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 21.1 MB/s eta 0:00:00
2026-01-03 00:26:45.125800 | controller | Installing collected packages: pip
2026-01-03 00:26:45.126113 | controller |   Attempting uninstall: pip
2026-01-03 00:26:45.129433 | controller |     Found existing installation: pip 22.2.2
2026-01-03 00:26:45.364491 | controller |     Uninstalling pip-22.2.2:
2026-01-03 00:26:45.393661 | controller |       Successfully uninstalled pip-22.2.2
2026-01-03 00:26:47.258983 | controller | Successfully installed pip-25.3
2026-01-03 00:26:48.090453 | controller | ok: Runtime: 0:00:03.463108
2026-01-03 00:26:48.096651 | 
2026-01-03 00:26:48.096720 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-03 00:26:48.967948 | controller | changed
2026-01-03 00:26:48.982157 | 
2026-01-03 00:26:48.982302 | TASK [Install ansible into virtualenv]
2026-01-03 00:26:50.173412 | controller | Processing ./src/github.com/ansible/ansible
2026-01-03 00:26:50.179181 | controller |   Installing build dependencies: started
2026-01-03 00:26:52.052740 | controller |   Installing build dependencies: finished with status 'done'
2026-01-03 00:26:53.611045 | controller |   Getting requirements to build wheel: started
2026-01-03 00:26:53.611125 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-03 00:26:53.611447 | controller |   Preparing metadata (pyproject.toml): started
2026-01-03 00:26:54.423387 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-03 00:26:54.428285 | 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-03 00:26:54.432687 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-03 00:26:54.875088 | controller | ERROR
2026-01-03 00:26:54.875401 | controller | {
2026-01-03 00:26:54.875463 | controller |   "delta": "0:00:04.938551",
2026-01-03 00:26:54.875504 | controller |   "end": "2026-01-03 00:26:54.577492",
2026-01-03 00:26:54.875541 | controller |   "msg": "non-zero return code",
2026-01-03 00:26:54.875596 | controller |   "rc": 1,
2026-01-03 00:26:54.875633 | controller |   "start": "2026-01-03 00:26:49.638941"
2026-01-03 00:26:54.875668 | controller | }
failure
2026-01-03 00:26:54.878561 | 
2026-01-03 00:26:54.878659 | PLAY RECAP
2026-01-03 00:26:54.878741 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-03 00:26:54.878784 | 
2026-01-03 00:26:55.008228 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-03 00:26:55.009263 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-03 00:26:55.651663 | 
2026-01-03 00:26:55.651803 | PLAY [all]
2026-01-03 00:26:55.676805 | 
2026-01-03 00:26:55.676985 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-03 00:26:57.520659 | controller | changed: non-zero return code
2026-01-03 00:26:57.535072 | 
2026-01-03 00:26:57.535309 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-03 00:26:57.562809 | controller | skipping: Conditional result was False
2026-01-03 00:26:57.576949 | 
2026-01-03 00:26:57.577434 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-03 00:26:57.620744 | 
2026-01-03 00:26:57.621117 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-03 00:26:57.662323 | 
2026-01-03 00:26:57.662613 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-03 00:26:57.689840 | controller | skipping: Conditional result was False
2026-01-03 00:26:57.704786 | 
2026-01-03 00:26:57.704967 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-03 00:26:57.747295 | 
2026-01-03 00:26:57.747740 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-03 00:26:57.775416 | controller | skipping: Conditional result was False
2026-01-03 00:26:57.789184 | 
2026-01-03 00:26:57.789353 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-03 00:26:57.816302 | controller | skipping: Conditional result was False
2026-01-03 00:26:57.834295 | 
2026-01-03 00:26:57.834489 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-03 00:26:57.861929 | controller | skipping: Conditional result was False
2026-01-03 00:26:57.915675 | 
2026-01-03 00:26:57.915798 | PLAY RECAP
2026-01-03 00:26:57.915857 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-03 00:26:57.915888 | 
2026-01-03 00:26:58.032384 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-03 00:26:58.033266 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-03 00:26:58.673073 | 
2026-01-03 00:26:58.673350 | PLAY [all:!appliance*]
2026-01-03 00:26:58.700348 | 
2026-01-03 00:26:58.700493 | TASK [unregister the node]
2026-01-03 00:26:59.056492 | controller | skipping: Conditional result was False
2026-01-03 00:26:59.073937 | 
2026-01-03 00:26:59.074222 | TASK [include_role : fetch-output]
2026-01-03 00:26:59.120859 | controller | ok
2026-01-03 00:26:59.150895 | 
2026-01-03 00:26:59.151053 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-03 00:26:59.206884 | controller | skipping: Conditional result was False
2026-01-03 00:26:59.215849 | 
2026-01-03 00:26:59.215978 | TASK [fetch-output : Set log path for single node]
2026-01-03 00:26:59.266486 | controller | ok
2026-01-03 00:26:59.279634 | 
2026-01-03 00:26:59.279739 | LOOP [fetch-output : Ensure local output dirs]
2026-01-03 00:26:59.707177 | controller -> localhost | ok: "/var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/logs"
2026-01-03 00:26:59.971275 | controller -> localhost | changed: "/var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/artifacts"
2026-01-03 00:27:00.184167 | controller -> localhost | changed: "/var/lib/zuul/builds/84796b5a779f4955b82a9baa3cc079b2/work/docs"
2026-01-03 00:27:00.202248 | 
2026-01-03 00:27:00.202425 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-03 00:27:02.495156 | controller | changed:
2026-01-03 00:27:02.495631 | controller | .d..t...... ./
2026-01-03 00:27:02.495741 | controller | cd+++++++++ controller/
2026-01-03 00:27:02.495854 | controller | changed: All items complete
2026-01-03 00:27:02.495965 | 
2026-01-03 00:27:04.557782 | controller | changed: .d..t...... ./
2026-01-03 00:27:06.624904 | controller | changed: .d..t...... ./
2026-01-03 00:27:06.652170 | 
2026-01-03 00:27:06.652316 | TASK [include_role : fetch-output-openshift]
2026-01-03 00:27:06.668485 | controller | skipping: Conditional result was False
2026-01-03 00:27:06.679936 | 
2026-01-03 00:27:06.680136 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-03 00:27:06.706581 | controller | skipping: Conditional result was False
2026-01-03 00:27:06.718626 | controller | skipping: Conditional result was False
2026-01-03 00:27:06.770278 | 
2026-01-03 00:27:06.770403 | PLAY [localhost]
2026-01-03 00:27:06.789199 | 
2026-01-03 00:27:06.789350 | TASK [Run Zuul manifest role]
2026-01-03 00:27:06.818748 | localhost | ok
2026-01-03 00:27:06.836468 | 
2026-01-03 00:27:06.836588 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-03 00:27:07.262255 | localhost | changed
2026-01-03 00:27:07.267375 | 
2026-01-03 00:27:07.267460 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-03 00:27:07.295144 | localhost | ok
2026-01-03 00:27:07.303039 | 
2026-01-03 00:27:07.303127 | TASK [Set zuul-log-path fact]
2026-01-03 00:27:07.322047 | localhost | ok
2026-01-03 00:27:07.361749 | 
2026-01-03 00:27:07.361864 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-03 00:27:07.390275 | localhost | ok
2026-01-03 00:27:07.398521 | 
2026-01-03 00:27:07.398615 | LOOP [Run upload-logs-swift role]
2026-01-03 00:27:07.432898 | localhost | Output suppressed because no_log was given
2026-01-03 00:27:07.464515 | 
2026-01-03 00:27:07.464632 | TASK [Set zuul-log-path fact]
2026-01-03 00:27:07.489348 | localhost | skipping: Conditional result was False
2026-01-03 00:27:07.501218 | 
2026-01-03 00:27:07.501398 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-03 00:27:07.937358 | localhost -> localhost | ok: Runtime: 0:00:00.005603
2026-01-03 00:27:07.942949 | 
2026-01-03 00:27:07.943057 | TASK [upload-logs-swift : Upload logs to swift]