2026-02-09 00:06:54.952918 | Job console starting...
2026-02-09 00:06:54.962540 | Updating repositories
2026-02-09 00:06:55.075576 | Preparing job workspace
2026-02-09 00:06:59.409132 | Running Ansible setup...
2026-02-09 00:07:04.216326 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-09 00:07:04.833920 | 
2026-02-09 00:07:04.834066 | PLAY [localhost]
2026-02-09 00:07:04.843408 | 
2026-02-09 00:07:04.843515 | TASK [Gathering Facts]
2026-02-09 00:07:05.901217 | localhost | ok
2026-02-09 00:07:05.919388 | 
2026-02-09 00:07:05.919514 | TASK [Setup log path fact]
2026-02-09 00:07:05.939932 | localhost | ok
2026-02-09 00:07:05.958652 | 
2026-02-09 00:07:05.958772 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-09 00:07:05.989655 | localhost | ok
2026-02-09 00:07:06.002668 | 
2026-02-09 00:07:06.002773 | TASK [emit-job-header : Print job information]
2026-02-09 00:07:06.044151 | # Job Information
2026-02-09 00:07:06.044321 | Ansible Version: 2.15.12
2026-02-09 00:07:06.044361 | Job: ansible-test-sanity-docker-devel
2026-02-09 00:07:06.044387 | Pipeline: periodic
2026-02-09 00:07:06.044411 | Executor: ze01.softwarefactory-project.io
2026-02-09 00:07:06.044434 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-09 00:07:06.044460 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a25/ansible/a252c5f0eda64e05a2997a8b531697f5/
2026-02-09 00:07:06.044482 | Event ID: 3991a479362c4ac7b1894c2bd5156053
2026-02-09 00:07:06.049330 | 
2026-02-09 00:07:06.049405 | LOOP [emit-job-header : Print node information]
2026-02-09 00:07:06.149222 | localhost | ok:
2026-02-09 00:07:06.149367 | localhost | # Node Information
2026-02-09 00:07:06.149395 | localhost | Inventory Hostname: controller
2026-02-09 00:07:06.149415 | localhost | Hostname: np0005613121
2026-02-09 00:07:06.149434 | localhost | Username: zuul
2026-02-09 00:07:06.149455 | localhost | Distro: Fedora 37
2026-02-09 00:07:06.149473 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-09 00:07:06.149492 | localhost | Region: ca-ymq-1
2026-02-09 00:07:06.149509 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-09 00:07:06.149526 | localhost | Product Name: OpenStack Nova
2026-02-09 00:07:06.149543 | localhost | Interface IP: 162.253.55.36
2026-02-09 00:07:06.167256 | 
2026-02-09 00:07:06.167397 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-09 00:07:06.667655 | localhost -> localhost | changed
2026-02-09 00:07:06.675276 | 
2026-02-09 00:07:06.675412 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-09 00:07:07.751465 | localhost -> localhost | changed
2026-02-09 00:07:07.776503 | 
2026-02-09 00:07:07.776594 | PLAY [all:!appliance*]
2026-02-09 00:07:07.838527 | 
2026-02-09 00:07:07.838685 | TASK [include_role : start-zuul-console]
2026-02-09 00:07:07.861726 | controller | ok
2026-02-09 00:07:07.881755 | 
2026-02-09 00:07:07.881885 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-09 00:07:08.335214 | controller | ok
2026-02-09 00:07:08.363944 | 
2026-02-09 00:07:08.364107 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-09 00:07:09.317664 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-09 00:07:09.325521 | 
2026-02-09 00:07:09.325631 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-09 00:07:09.870203 | controller | skipping: Conditional result was False
2026-02-09 00:07:09.881278 | 
2026-02-09 00:07:09.881416 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-09 00:07:09.916678 | controller | skipping: Conditional result was False
2026-02-09 00:07:09.927123 | 
2026-02-09 00:07:09.927281 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-09 00:07:09.954351 | controller | skipping: Conditional result was False
2026-02-09 00:07:09.967755 | 
2026-02-09 00:07:09.967912 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-09 00:07:10.006715 | controller | skipping: Conditional result was False
2026-02-09 00:07:10.018696 | 
2026-02-09 00:07:10.018880 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-09 00:07:10.046425 | controller | skipping: Conditional result was False
2026-02-09 00:07:10.066557 | 
2026-02-09 00:07:10.066742 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-09 00:07:10.091664 | controller | skipping: Conditional result was False
2026-02-09 00:07:10.106429 | 
2026-02-09 00:07:10.106563 | TASK [Disable Fedora Modular]
2026-02-09 00:07:10.363728 | controller | changed
2026-02-09 00:07:10.380506 | 
2026-02-09 00:07:10.380644 | TASK [Enable EPEL]
2026-02-09 00:07:10.407203 | controller | skipping: Conditional result was False
2026-02-09 00:07:10.417492 | 
2026-02-09 00:07:10.417626 | TASK [Register the RHEL node]
2026-02-09 00:07:10.970846 | 
2026-02-09 00:07:10.971055 | TASK [Show the subscription-manager status]
2026-02-09 00:07:11.545458 | controller | skipping: Conditional result was False
2026-02-09 00:07:11.560982 | 
2026-02-09 00:07:11.561186 | TASK [Enable EPEL on RHEL]
2026-02-09 00:07:12.115579 | controller | skipping: Conditional result was False
2026-02-09 00:07:12.127078 | 
2026-02-09 00:07:12.127241 | TASK [Install git and tox]
2026-02-09 00:08:33.486121 | controller | changed
2026-02-09 00:08:33.502332 | 
2026-02-09 00:08:33.502487 | TASK [include_role : prepare-workspace]
2026-02-09 00:08:33.545089 | controller | ok
2026-02-09 00:08:33.582954 | 
2026-02-09 00:08:33.583132 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-09 00:08:33.831101 | controller | ok
2026-02-09 00:08:33.840907 | 
2026-02-09 00:08:33.840995 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-09 00:14:10.693870 | controller | Output suppressed because no_log was given
2026-02-09 00:14:10.717523 | 
2026-02-09 00:14:10.717664 | TASK [include_role : prepare-workspace-openshift]
2026-02-09 00:14:10.747808 | controller | skipping: Conditional result was False
2026-02-09 00:14:10.775246 | 
2026-02-09 00:14:10.775336 | PLAY [all:!appliance]
2026-02-09 00:14:10.829984 | 
2026-02-09 00:14:10.830238 | TASK [Run add-build-sshkey role (RSA)]
2026-02-09 00:14:10.863160 | controller | ok
2026-02-09 00:14:10.885554 | 
2026-02-09 00:14:10.885702 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-09 00:14:11.241099 | controller -> localhost | ok
2026-02-09 00:14:11.250737 | 
2026-02-09 00:14:11.250886 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-09 00:14:11.284443 | controller | ok
2026-02-09 00:14:11.305830 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-09 00:14:11.315347 | 
2026-02-09 00:14:11.315486 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-09 00:14:11.877600 | controller -> localhost | Generating public/private rsa key pair.
2026-02-09 00:14:11.877845 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_rsa.
2026-02-09 00:14:11.877883 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_rsa.pub.
2026-02-09 00:14:11.877909 | controller -> localhost | The key fingerprint is:
2026-02-09 00:14:11.877930 | controller -> localhost | SHA256:4YBlwtvRLvMvzhBBJeEeuKkZmMtf73jHfjbdwVJrozo zuul-build-sshkey
2026-02-09 00:14:11.877950 | controller -> localhost | The key's randomart image is:
2026-02-09 00:14:11.877969 | controller -> localhost | +---[RSA 2048]----+
2026-02-09 00:14:11.877987 | controller -> localhost | |   .. *+.        |
2026-02-09 00:14:11.878006 | controller -> localhost | |    .O...        |
2026-02-09 00:14:11.878055 | controller -> localhost | |    oo=o.        |
2026-02-09 00:14:11.878075 | controller -> localhost | | o  .++=..     . |
2026-02-09 00:14:11.878092 | controller -> localhost | |o . o o+S     o .|
2026-02-09 00:14:11.878121 | controller -> localhost | |.. +   ..    . * |
2026-02-09 00:14:11.878144 | controller -> localhost | |..o  .. ..  . = o|
2026-02-09 00:14:11.878168 | controller -> localhost | |  . . o+.o.E o . |
2026-02-09 00:14:11.878194 | controller -> localhost | |   . .o+=oo.+    |
2026-02-09 00:14:11.878221 | controller -> localhost | +----[SHA256]-----+
2026-02-09 00:14:11.878270 | controller -> localhost | ok: Runtime: 0:00:00.089227
2026-02-09 00:14:11.888871 | 
2026-02-09 00:14:11.889010 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-09 00:14:11.921714 | controller | ok
2026-02-09 00:14:11.933557 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-09 00:14:11.944705 | 
2026-02-09 00:14:11.944846 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-09 00:14:11.959639 | controller | skipping: Conditional result was False
2026-02-09 00:14:11.967974 | 
2026-02-09 00:14:11.968162 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-09 00:14:12.637274 | controller | changed
2026-02-09 00:14:12.653155 | 
2026-02-09 00:14:12.653347 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-09 00:14:12.885169 | controller | ok
2026-02-09 00:14:12.895571 | 
2026-02-09 00:14:12.895705 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-09 00:14:13.602763 | controller | changed
2026-02-09 00:14:13.608844 | 
2026-02-09 00:14:13.608926 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-09 00:14:14.295831 | controller | changed
2026-02-09 00:14:14.305651 | 
2026-02-09 00:14:14.305763 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-09 00:14:14.351631 | controller | skipping: Conditional result was False
2026-02-09 00:14:14.364675 | 
2026-02-09 00:14:14.364810 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-09 00:14:14.844307 | controller -> localhost | changed
2026-02-09 00:14:14.860611 | 
2026-02-09 00:14:14.860747 | TASK [add-build-sshkey : Add back temp key]
2026-02-09 00:14:15.194794 | controller -> localhost | Identity added: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_rsa (zuul-build-sshkey)
2026-02-09 00:14:15.195109 | controller -> localhost | ok: Runtime: 0:00:00.012492
2026-02-09 00:14:15.205261 | 
2026-02-09 00:14:15.205401 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-09 00:14:15.604324 | controller | ok
2026-02-09 00:14:15.610264 | 
2026-02-09 00:14:15.610341 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-09 00:14:15.637125 | controller | skipping: Conditional result was False
2026-02-09 00:14:15.652856 | 
2026-02-09 00:14:15.653187 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-09 00:14:15.680902 | controller | ok
2026-02-09 00:14:15.699509 | 
2026-02-09 00:14:15.699637 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-09 00:14:16.009784 | controller -> localhost | ok
2026-02-09 00:14:16.017137 | 
2026-02-09 00:14:16.017248 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-09 00:14:16.039654 | controller | ok
2026-02-09 00:14:16.051418 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-09 00:14:16.058132 | 
2026-02-09 00:14:16.058210 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-09 00:14:16.356991 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-09 00:14:16.357320 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_ecdsa.
2026-02-09 00:14:16.357380 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_ecdsa.pub.
2026-02-09 00:14:16.357436 | controller -> localhost | The key fingerprint is:
2026-02-09 00:14:16.357479 | controller -> localhost | SHA256:x8pljHuiPmePbuodQmkbnU1LaPWbLa0FHi4L8wTU1qA zuul-build-sshkey
2026-02-09 00:14:16.357519 | controller -> localhost | The key's randomart image is:
2026-02-09 00:14:16.357557 | controller -> localhost | +---[ECDSA 521]---+
2026-02-09 00:14:16.357595 | controller -> localhost | |        ..oo     |
2026-02-09 00:14:16.357632 | controller -> localhost | |       . +o..    |
2026-02-09 00:14:16.357670 | controller -> localhost | |        E.o +    |
2026-02-09 00:14:16.357706 | controller -> localhost | |       + X + B   |
2026-02-09 00:14:16.357743 | controller -> localhost | |      = S @ * +  |
2026-02-09 00:14:16.357779 | controller -> localhost | |     o + @ o +   |
2026-02-09 00:14:16.357815 | controller -> localhost | |      o * + .    |
2026-02-09 00:14:16.357852 | controller -> localhost | |      .++=       |
2026-02-09 00:14:16.357888 | controller -> localhost | |     o=B+..      |
2026-02-09 00:14:16.357925 | controller -> localhost | +----[SHA256]-----+
2026-02-09 00:14:16.358008 | controller -> localhost | ok: Runtime: 0:00:00.011124
2026-02-09 00:14:16.373252 | 
2026-02-09 00:14:16.373404 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-09 00:14:16.407649 | controller | ok
2026-02-09 00:14:16.418369 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-09 00:14:16.428529 | 
2026-02-09 00:14:16.428640 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-09 00:14:16.453699 | controller | skipping: Conditional result was False
2026-02-09 00:14:16.463007 | 
2026-02-09 00:14:16.463158 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-09 00:14:16.742365 | controller | changed
2026-02-09 00:14:16.752131 | 
2026-02-09 00:14:16.752253 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-09 00:14:16.998474 | controller | ok
2026-02-09 00:14:17.053478 | 
2026-02-09 00:14:17.053643 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-09 00:14:17.721454 | controller | changed
2026-02-09 00:14:17.730261 | 
2026-02-09 00:14:17.730373 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-09 00:14:18.417761 | controller | changed
2026-02-09 00:14:18.427802 | 
2026-02-09 00:14:18.427894 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-09 00:14:18.452827 | controller | skipping: Conditional result was False
2026-02-09 00:14:18.461996 | 
2026-02-09 00:14:18.462151 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-09 00:14:18.743208 | controller -> localhost | changed
2026-02-09 00:14:18.769602 | 
2026-02-09 00:14:18.769765 | TASK [add-build-sshkey : Add back temp key]
2026-02-09 00:14:19.076890 | controller -> localhost | Identity added: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/a252c5f0eda64e05a2997a8b531697f5_id_ecdsa (zuul-build-sshkey)
2026-02-09 00:14:19.077201 | controller -> localhost | ok: Runtime: 0:00:00.015422
2026-02-09 00:14:19.084482 | 
2026-02-09 00:14:19.084586 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-09 00:14:19.320631 | controller | ok
2026-02-09 00:14:19.335294 | 
2026-02-09 00:14:19.335575 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-09 00:14:19.374086 | controller | skipping: Conditional result was False
2026-02-09 00:14:19.402949 | 
2026-02-09 00:14:19.403162 | TASK [include_role : remove-zuul-sshkey]
2026-02-09 00:14:19.428766 | controller | skipping: Conditional result was False
2026-02-09 00:14:19.439214 | 
2026-02-09 00:14:19.439450 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-09 00:14:19.694461 | controller | ok: "logs"
2026-02-09 00:14:19.694799 | controller | ok: All items complete
2026-02-09 00:14:19.694853 | 
2026-02-09 00:14:19.897672 | controller | ok: "artifacts"
2026-02-09 00:14:20.104848 | controller | ok: "docs"
2026-02-09 00:14:20.121979 | 
2026-02-09 00:14:20.122145 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-09 00:14:20.372630 | controller | changed: "logs"
2026-02-09 00:14:20.588520 | controller | changed: "artifacts"
2026-02-09 00:14:20.785826 | controller | changed: "docs"
2026-02-09 00:14:20.817207 | 
2026-02-09 00:14:20.817320 | PLAY RECAP
2026-02-09 00:14:20.817367 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-09 00:14:20.817393 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-09 00:14:20.817411 | 
2026-02-09 00:14:20.953116 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-09 00:14:20.954791 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-09 00:14:21.562764 | 
2026-02-09 00:14:21.562922 | PLAY [all]
2026-02-09 00:14:21.589322 | 
2026-02-09 00:14:21.589458 | TASK [Install binary dependencies]
2026-02-09 00:14:21.640362 | controller | ok
2026-02-09 00:14:21.660318 | 
2026-02-09 00:14:21.660448 | TASK [bindep : Include find tasks]
2026-02-09 00:14:21.690953 | controller | ok
2026-02-09 00:14:21.700563 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-09 00:14:21.708918 | 
2026-02-09 00:14:21.709077 | TASK [bindep : Look for bindep.txt]
2026-02-09 00:14:22.337922 | controller | ok
2026-02-09 00:14:22.360407 | 
2026-02-09 00:14:22.360553 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:14:22.376279 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.387071 | 
2026-02-09 00:14:22.387264 | TASK [bindep : Look for other-requirements.txt]
2026-02-09 00:14:22.618441 | controller | ok
2026-02-09 00:14:22.630154 | 
2026-02-09 00:14:22.630310 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:14:22.657755 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.672115 | 
2026-02-09 00:14:22.672272 | TASK [bindep : Look for bindep fallback file]
2026-02-09 00:14:22.709444 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.716740 | 
2026-02-09 00:14:22.716977 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:14:22.741955 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.749581 | 
2026-02-09 00:14:22.749695 | TASK [bindep : Include bindep tasks]
2026-02-09 00:14:22.773982 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.780924 | 
2026-02-09 00:14:22.781069 | TASK [bindep : Include install tasks]
2026-02-09 00:14:22.804931 | controller | skipping: Conditional result was False
2026-02-09 00:14:22.811865 | 
2026-02-09 00:14:22.811979 | LOOP [bindep : Include package tasks]
2026-02-09 00:14:22.875606 | 
2026-02-09 00:14:22.875805 | TASK [Run test-setup role]
2026-02-09 00:14:22.902908 | controller | ok
2026-02-09 00:14:22.930938 | 
2026-02-09 00:14:22.931097 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-09 00:14:23.149728 | controller | ok
2026-02-09 00:14:23.158944 | 
2026-02-09 00:14:23.159095 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-09 00:14:23.702481 | controller | skipping: Conditional result was False
2026-02-09 00:14:23.739848 | 
2026-02-09 00:14:23.739947 | PLAY RECAP
2026-02-09 00:14:23.739988 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-09 00:14:23.740009 | 
2026-02-09 00:14:23.866506 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-09 00:14:23.867464 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-09 00:14:24.513367 | 
2026-02-09 00:14:24.513519 | PLAY [controller]
2026-02-09 00:14:24.537817 | 
2026-02-09 00:14:24.537970 | TASK [Create the /root directory]
2026-02-09 00:14:25.205879 | controller | ok
2026-02-09 00:14:25.220234 | 
2026-02-09 00:14:25.220395 | TASK [Install glibc-langpack-en]
2026-02-09 00:14:29.436320 | controller | ok: Nothing to do
2026-02-09 00:14:29.449576 | 
2026-02-09 00:14:29.449716 | TASK [Ensure controller directory exists]
2026-02-09 00:14:29.698963 | controller | changed
2026-02-09 00:14:29.709163 | 
2026-02-09 00:14:29.709273 | TASK [Install container runtime]
2026-02-09 00:14:29.761963 | controller | ok
2026-02-09 00:14:29.808524 | 
2026-02-09 00:14:29.808668 | LOOP [ensure-podman : Find distribution installation]
2026-02-09 00:14:29.834371 | controller | ok: "/var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-09 00:14:29.842726 | controller | included: /var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-09 00:14:29.849610 | 
2026-02-09 00:14:29.849676 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-09 00:15:37.259485 | controller | changed
2026-02-09 00:15:37.266677 | 
2026-02-09 00:15:37.266763 | TASK [ensure-podman : Fetch podman version]
2026-02-09 00:15:37.808600 | controller | Client:       Podman Engine
2026-02-09 00:15:37.835183 | controller | Version:      4.6.2
2026-02-09 00:15:37.835329 | controller | API Version:  4.6.2
2026-02-09 00:15:37.835345 | controller | Go Version:   go1.19.12
2026-02-09 00:15:37.835373 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-09 00:15:37.835386 | controller | OS/Arch:      linux/amd64
2026-02-09 00:15:38.303124 | controller | ok: Runtime: 0:00:00.188917
2026-02-09 00:15:38.317420 | 
2026-02-09 00:15:38.317556 | TASK [ensure-podman : Print podman version installed]
2026-02-09 00:15:38.367737 | Podman version: Client:       Podman Engine
2026-02-09 00:15:38.368371 | Version:      4.6.2
2026-02-09 00:15:38.368465 | API Version:  4.6.2
2026-02-09 00:15:38.368533 | Go Version:   go1.19.12
2026-02-09 00:15:38.368597 | Built:        Mon Aug 28 19:38:31 2023
2026-02-09 00:15:38.368663 | OS/Arch:      linux/amd64
2026-02-09 00:15:38.382864 | 
2026-02-09 00:15:38.383007 | TASK [ensure-podman : Validate podman engine]
2026-02-09 00:15:38.925871 | controller | skipping: Conditional result was False
2026-02-09 00:15:38.935508 | 
2026-02-09 00:15:38.935644 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-09 00:15:38.961333 | controller | skipping: Conditional result was False
2026-02-09 00:15:38.983968 | 
2026-02-09 00:15:38.984166 | TASK [Ensure python3.8 is present]
2026-02-09 00:15:39.006626 | controller | skipping: Conditional result was False
2026-02-09 00:15:39.017172 | 
2026-02-09 00:15:39.017309 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-09 00:15:39.042088 | controller | ok
2026-02-09 00:15:39.075089 | 
2026-02-09 00:15:39.075231 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-09 00:15:40.469667 | controller | ok: Nothing to do
2026-02-09 00:15:40.476094 | 
2026-02-09 00:15:40.476180 | TASK [our-ensure-python : Also install python3-devel]
2026-02-09 00:15:49.998977 | controller | changed
2026-02-09 00:15:50.011651 | 
2026-02-09 00:15:50.011790 | TASK [Run ensure-virtualenv role]
2026-02-09 00:15:50.032929 | controller | ok
2026-02-09 00:15:50.056377 | 
2026-02-09 00:15:50.056603 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-09 00:15:50.263385 | controller | /usr/bin/virtualenv
2026-02-09 00:15:50.586931 | controller | ok: Runtime: 0:00:00.005205
2026-02-09 00:15:50.597008 | 
2026-02-09 00:15:50.597206 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-09 00:15:50.661913 | controller | skipping: Conditional result was False
2026-02-09 00:15:50.662401 | controller | ok: All items complete
2026-02-09 00:15:50.662468 | 
2026-02-09 00:15:50.688876 | 
2026-02-09 00:15:50.689046 | TASK [Find the full path of the Python interpreter]
2026-02-09 00:15:50.951979 | controller | /usr/bin/python3
2026-02-09 00:15:51.271191 | controller | ok
2026-02-09 00:15:51.280314 | 
2026-02-09 00:15:51.280461 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-09 00:15:52.129495 | controller | created virtual environment CPython3.11.0.final.0-64 in 469ms
2026-02-09 00:15:52.146731 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-09 00:15:52.146769 | 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-09 00:15:52.146777 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-09 00:15:52.146791 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-09 00:15:52.330104 | controller | changed
2026-02-09 00:15:52.336368 | 
2026-02-09 00:15:52.336460 | TASK [Set selinux package]
2026-02-09 00:15:52.359121 | controller | ok
2026-02-09 00:15:52.371602 | 
2026-02-09 00:15:52.371724 | TASK [Set selinux package (Fedora)]
2026-02-09 00:15:52.401411 | controller | ok
2026-02-09 00:15:52.407416 | 
2026-02-09 00:15:52.407486 | TASK [Install selinux into virtualenv]
2026-02-09 00:16:17.813390 | controller | Collecting selinux-please-lie-to-me
2026-02-09 00:16:30.079151 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-09 00:16:30.408540 | controller | Collecting setuptools<50.0.0
2026-02-09 00:16:30.414857 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-09 00:16:30.464367 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 18.2 MB/s eta 0:00:00
2026-02-09 00:16:30.549619 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-09 00:16:30.549787 | controller |   Attempting uninstall: setuptools
2026-02-09 00:16:30.552149 | controller |     Found existing installation: setuptools 62.6.0
2026-02-09 00:16:30.614456 | controller |     Uninstalling setuptools-62.6.0:
2026-02-09 00:16:30.622421 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-09 00:16:30.978806 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-09 00:16:42.454579 | controller |
2026-02-09 00:16:42.550320 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-09 00:16:42.550370 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-09 00:16:42.969496 | controller | ok: Runtime: 0:00:49.943281
2026-02-09 00:16:42.978401 | 
2026-02-09 00:16:42.978537 | TASK [Install pytest-forked into virtualenv]
2026-02-09 00:16:52.643936 | controller | Collecting pytest-forked
2026-02-09 00:17:04.958569 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-09 00:17:05.007032 | controller | Collecting py
2026-02-09 00:17:05.011457 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-09 00:17:05.038038 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.9 MB/s eta 0:00:00
2026-02-09 00:17:05.146038 | controller | Collecting pytest>=3.10
2026-02-09 00:17:05.151430 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-09 00:17:05.163887 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 39.1 MB/s eta 0:00:00
2026-02-09 00:17:05.202687 | controller | Collecting iniconfig>=1.0.1
2026-02-09 00:17:05.206121 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-09 00:17:05.251764 | controller | Collecting packaging>=22
2026-02-09 00:17:05.255971 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-09 00:17:05.264858 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.3 MB/s eta 0:00:00
2026-02-09 00:17:05.297085 | controller | Collecting pluggy<2,>=1.5
2026-02-09 00:17:05.300393 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-09 00:17:05.347706 | controller | Collecting pygments>=2.7.2
2026-02-09 00:17:05.363686 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-09 00:17:05.386868 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 61.0 MB/s eta 0:00:00
2026-02-09 00:17:05.456153 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-09 00:17:06.484930 | 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-09 00:17:06.493942 | controller |
2026-02-09 00:17:06.561592 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-09 00:17:06.561622 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-09 00:17:07.031026 | controller | ok: Runtime: 0:00:23.358486
2026-02-09 00:17:07.036837 | 
2026-02-09 00:17:07.036903 | TASK [Update pip]
2026-02-09 00:17:07.577585 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-09 00:17:17.340793 | controller | Collecting pip
2026-02-09 00:17:29.519567 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-09 00:17:29.570562 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 40.1 MB/s eta 0:00:00
2026-02-09 00:17:29.641565 | controller | Installing collected packages: pip
2026-02-09 00:17:29.643234 | controller |   Attempting uninstall: pip
2026-02-09 00:17:29.643277 | controller |     Found existing installation: pip 22.2.2
2026-02-09 00:17:29.778860 | controller |     Uninstalling pip-22.2.2:
2026-02-09 00:17:29.793894 | controller |       Successfully uninstalled pip-22.2.2
2026-02-09 00:17:30.619283 | controller | Successfully installed pip-26.0.1
2026-02-09 00:17:31.083354 | controller | ok: Runtime: 0:00:23.449235
2026-02-09 00:17:31.089909 | 
2026-02-09 00:17:31.090008 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-09 00:17:31.322456 | controller | changed
2026-02-09 00:17:31.334638 | 
2026-02-09 00:17:31.334815 | TASK [Install ansible into virtualenv]
2026-02-09 00:17:31.855046 | controller | Processing ./src/github.com/ansible/ansible
2026-02-09 00:17:31.857413 | controller |   Installing build dependencies: started
2026-02-09 00:17:54.465160 | controller |   Installing build dependencies: finished with status 'done'
2026-02-09 00:17:54.465345 | controller |   Getting requirements to build wheel: started
2026-02-09 00:17:55.310231 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-09 00:17:55.311841 | controller |   Preparing metadata (pyproject.toml): started
2026-02-09 00:17:55.845075 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-09 00:17:55.850868 | 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-09 00:17:55.857363 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-09 00:17:56.396493 | controller | ERROR
2026-02-09 00:17:56.396767 | controller | {
2026-02-09 00:17:56.396834 | controller |   "delta": "0:00:24.376940",
2026-02-09 00:17:56.396959 | controller |   "end": "2026-02-09 00:17:55.943691",
2026-02-09 00:17:56.397071 | controller |   "msg": "non-zero return code",
2026-02-09 00:17:56.397135 | controller |   "rc": 1,
2026-02-09 00:17:56.397177 | controller |   "start": "2026-02-09 00:17:31.566751"
2026-02-09 00:17:56.397216 | controller | }
failure
2026-02-09 00:17:56.399529 | 
2026-02-09 00:17:56.399627 | PLAY RECAP
2026-02-09 00:17:56.399708 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-09 00:17:56.399812 | 
2026-02-09 00:17:56.533993 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-09 00:17:56.535310 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-09 00:17:57.160336 | 
2026-02-09 00:17:57.160473 | PLAY [all]
2026-02-09 00:17:57.200761 | 
2026-02-09 00:17:57.200897 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-09 00:17:57.688170 | controller | changed: non-zero return code
2026-02-09 00:17:57.712103 | 
2026-02-09 00:17:57.712309 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-09 00:17:57.738522 | controller | skipping: Conditional result was False
2026-02-09 00:17:57.747985 | 
2026-02-09 00:17:57.748161 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-09 00:17:57.783229 | 
2026-02-09 00:17:57.783456 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-09 00:17:57.817597 | 
2026-02-09 00:17:57.817799 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-09 00:17:57.833325 | controller | skipping: Conditional result was False
2026-02-09 00:17:57.845805 | 
2026-02-09 00:17:57.845962 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-09 00:17:57.879913 | 
2026-02-09 00:17:57.880149 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-09 00:17:57.895120 | controller | skipping: Conditional result was False
2026-02-09 00:17:57.904934 | 
2026-02-09 00:17:57.905099 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-09 00:17:57.930567 | controller | skipping: Conditional result was False
2026-02-09 00:17:57.939620 | 
2026-02-09 00:17:57.939752 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-09 00:17:57.965131 | controller | skipping: Conditional result was False
2026-02-09 00:17:58.001163 | 
2026-02-09 00:17:58.001326 | PLAY RECAP
2026-02-09 00:17:58.001382 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-09 00:17:58.001404 | 
2026-02-09 00:17:58.113051 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-09 00:17:58.114836 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-09 00:17:58.786878 | 
2026-02-09 00:17:58.787043 | PLAY [all:!appliance*]
2026-02-09 00:17:58.824096 | 
2026-02-09 00:17:58.824245 | TASK [unregister the node]
2026-02-09 00:17:59.357155 | controller | skipping: Conditional result was False
2026-02-09 00:17:59.371756 | 
2026-02-09 00:17:59.372007 | TASK [include_role : fetch-output]
2026-02-09 00:17:59.416748 | controller | ok
2026-02-09 00:17:59.449242 | 
2026-02-09 00:17:59.449389 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-09 00:17:59.525801 | controller | skipping: Conditional result was False
2026-02-09 00:17:59.536091 | 
2026-02-09 00:17:59.536242 | TASK [fetch-output : Set log path for single node]
2026-02-09 00:17:59.592335 | controller | ok
2026-02-09 00:17:59.605278 | 
2026-02-09 00:17:59.605445 | LOOP [fetch-output : Ensure local output dirs]
2026-02-09 00:18:00.044523 | controller -> localhost | ok: "/var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/logs"
2026-02-09 00:18:00.339333 | controller -> localhost | changed: "/var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/artifacts"
2026-02-09 00:18:00.584210 | controller -> localhost | changed: "/var/lib/zuul/builds/a252c5f0eda64e05a2997a8b531697f5/work/docs"
2026-02-09 00:18:00.605792 | 
2026-02-09 00:18:00.606001 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-09 00:18:01.332165 | controller | changed:
2026-02-09 00:18:01.332496 | controller | .d..t...... ./
2026-02-09 00:18:01.332559 | controller | cd+++++++++ controller/
2026-02-09 00:18:01.332629 | controller | changed: All items complete
2026-02-09 00:18:01.332675 | 
2026-02-09 00:18:01.883381 | controller | changed: .d..t...... ./
2026-02-09 00:18:02.372428 | controller | changed: .d..t...... ./
2026-02-09 00:18:02.386964 | 
2026-02-09 00:18:02.387120 | TASK [include_role : fetch-output-openshift]
2026-02-09 00:18:02.401353 | controller | skipping: Conditional result was False
2026-02-09 00:18:02.408734 | 
2026-02-09 00:18:02.408816 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-09 00:18:02.435384 | controller | skipping: Conditional result was False
2026-02-09 00:18:02.450993 | controller | skipping: Conditional result was False
2026-02-09 00:18:02.506586 | 
2026-02-09 00:18:02.506733 | PLAY [localhost]
2026-02-09 00:18:02.524706 | 
2026-02-09 00:18:02.524836 | TASK [Run Zuul manifest role]
2026-02-09 00:18:02.545531 | localhost | ok
2026-02-09 00:18:02.572362 | 
2026-02-09 00:18:02.572539 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-09 00:18:03.031263 | localhost | changed
2026-02-09 00:18:03.036850 | 
2026-02-09 00:18:03.036929 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-09 00:18:03.078095 | localhost | ok
2026-02-09 00:18:03.090907 | 
2026-02-09 00:18:03.091078 | TASK [Set zuul-log-path fact]
2026-02-09 00:18:03.113515 | localhost | ok
2026-02-09 00:18:03.137680 | 
2026-02-09 00:18:03.137810 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-09 00:18:03.181969 | localhost | ok
2026-02-09 00:18:03.195206 | 
2026-02-09 00:18:03.195317 | LOOP [Run upload-logs-swift role]
2026-02-09 00:18:03.243368 | localhost | Output suppressed because no_log was given
2026-02-09 00:18:03.283285 | 
2026-02-09 00:18:03.283428 | TASK [Set zuul-log-path fact]
2026-02-09 00:18:03.319145 | localhost | skipping: Conditional result was False
2026-02-09 00:18:03.326545 | 
2026-02-09 00:18:03.326638 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-09 00:18:03.761107 | localhost -> localhost | ok: Runtime: 0:00:00.008942
2026-02-09 00:18:03.799473 | 
2026-02-09 00:18:03.799605 | TASK [upload-logs-swift : Upload logs to swift]