2025-12-10 00:23:14.396852 | Job console starting...
2025-12-10 00:23:14.409973 | Updating repositories
2025-12-10 00:23:14.558234 | Preparing job workspace
2025-12-10 00:23:18.443336 | Running Ansible setup...
2025-12-10 00:23:26.046769 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-10 00:23:26.649013 | 
2025-12-10 00:23:26.649125 | PLAY [localhost]
2025-12-10 00:23:26.657091 | 
2025-12-10 00:23:26.657158 | TASK [Gathering Facts]
2025-12-10 00:23:27.689853 | localhost | ok
2025-12-10 00:23:27.725706 | 
2025-12-10 00:23:27.725937 | TASK [Setup log path fact]
2025-12-10 00:23:27.751826 | localhost | ok
2025-12-10 00:23:27.768026 | 
2025-12-10 00:23:27.768117 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 00:23:27.795903 | localhost | ok
2025-12-10 00:23:27.803792 | 
2025-12-10 00:23:27.803859 | TASK [emit-job-header : Print job information]
2025-12-10 00:23:27.831179 | # Job Information
2025-12-10 00:23:27.831329 | Ansible Version: 2.15.12
2025-12-10 00:23:27.831361 | Job: ansible-test-sanity-docker-milestone
2025-12-10 00:23:27.831383 | Pipeline: periodic
2025-12-10 00:23:27.831402 | Executor: ze03.softwarefactory-project.io
2025-12-10 00:23:27.831422 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-10 00:23:27.831444 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/810/ansible/8109bea8f6be48548e6b68be6a8bf824/
2025-12-10 00:23:27.831464 | Event ID: 6e49960649da492f963de05b327e4f7a
2025-12-10 00:23:27.835407 | 
2025-12-10 00:23:27.835470 | LOOP [emit-job-header : Print node information]
2025-12-10 00:23:27.934903 | localhost | ok:
2025-12-10 00:23:27.935188 | localhost | # Node Information
2025-12-10 00:23:27.935248 | localhost | Inventory Hostname: controller
2025-12-10 00:23:27.935292 | localhost | Hostname: np0005552601
2025-12-10 00:23:27.935333 | localhost | Username: zuul
2025-12-10 00:23:27.935378 | localhost | Distro: Fedora 37
2025-12-10 00:23:27.935418 | localhost | Provider: ansible-vexxhost-ams1
2025-12-10 00:23:27.935472 | localhost | Region: ams1
2025-12-10 00:23:27.935522 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-10 00:23:27.935560 | localhost | Product Name: OpenStack Nova
2025-12-10 00:23:27.935596 | localhost | Interface IP: 38.129.16.227
2025-12-10 00:23:27.957280 | 
2025-12-10 00:23:27.957469 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-10 00:23:28.361658 | localhost -> localhost | changed
2025-12-10 00:23:28.369351 | 
2025-12-10 00:23:28.369454 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-10 00:23:29.274276 | localhost -> localhost | changed
2025-12-10 00:23:29.293801 | 
2025-12-10 00:23:29.293855 | PLAY [all:!appliance*]
2025-12-10 00:23:29.309327 | 
2025-12-10 00:23:29.309390 | TASK [include_role : start-zuul-console]
2025-12-10 00:23:29.329145 | controller | ok
2025-12-10 00:23:29.342266 | 
2025-12-10 00:23:29.342327 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-10 00:23:30.432977 | controller | ok
2025-12-10 00:23:30.454762 | 
2025-12-10 00:23:30.454969 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-10 00:23:32.928813 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-10 00:23:32.943774 | 
2025-12-10 00:23:32.943915 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-10 00:23:33.321469 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.331062 | 
2025-12-10 00:23:33.331206 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-10 00:23:33.367386 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.377264 | 
2025-12-10 00:23:33.377360 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-10 00:23:33.413767 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.423159 | 
2025-12-10 00:23:33.423252 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-10 00:23:33.448968 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.457758 | 
2025-12-10 00:23:33.457854 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-10 00:23:33.484424 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.493826 | 
2025-12-10 00:23:33.493922 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-10 00:23:33.530063 | controller | skipping: Conditional result was False
2025-12-10 00:23:33.545182 | 
2025-12-10 00:23:33.545281 | TASK [Disable Fedora Modular]
2025-12-10 00:23:34.693219 | controller | changed
2025-12-10 00:23:34.702433 | 
2025-12-10 00:23:34.702535 | TASK [Enable EPEL]
2025-12-10 00:23:34.742014 | controller | skipping: Conditional result was False
2025-12-10 00:23:34.751771 | 
2025-12-10 00:23:34.751878 | TASK [Register the RHEL node]
2025-12-10 00:23:35.184852 | 
2025-12-10 00:23:35.185459 | TASK [Show the subscription-manager status]
2025-12-10 00:23:35.584684 | controller | skipping: Conditional result was False
2025-12-10 00:23:35.593533 | 
2025-12-10 00:23:35.593651 | TASK [Enable EPEL on RHEL]
2025-12-10 00:23:36.003127 | controller | skipping: Conditional result was False
2025-12-10 00:23:36.017283 | 
2025-12-10 00:23:36.017495 | TASK [Install git and tox]
2025-12-10 00:30:45.369589 | controller | changed
2025-12-10 00:30:45.382526 | 
2025-12-10 00:30:45.382651 | TASK [include_role : prepare-workspace]
2025-12-10 00:30:45.406297 | controller | ok
2025-12-10 00:30:45.440314 | 
2025-12-10 00:30:45.440481 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-10 00:30:46.290196 | controller | ok
2025-12-10 00:30:46.310026 | 
2025-12-10 00:30:46.310174 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-10 00:31:01.468745 | controller | Output suppressed because no_log was given
2025-12-10 00:31:01.483864 | 
2025-12-10 00:31:01.483951 | TASK [include_role : prepare-workspace-openshift]
2025-12-10 00:31:01.501605 | controller | skipping: Conditional result was False
2025-12-10 00:31:01.559240 | 
2025-12-10 00:31:01.559339 | PLAY [all:!appliance]
2025-12-10 00:31:01.575128 | 
2025-12-10 00:31:01.575186 | TASK [Run add-build-sshkey role (RSA)]
2025-12-10 00:31:01.594496 | controller | ok
2025-12-10 00:31:01.608828 | 
2025-12-10 00:31:01.609103 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-10 00:31:01.877224 | controller -> localhost | ok
2025-12-10 00:31:01.886037 | 
2025-12-10 00:31:01.886122 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-10 00:31:01.910548 | controller | ok
2025-12-10 00:31:01.929534 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-10 00:31:01.937720 | 
2025-12-10 00:31:01.937833 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-10 00:31:02.382903 | controller -> localhost | Generating public/private rsa key pair.
2025-12-10 00:31:02.383269 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_rsa.
2025-12-10 00:31:02.383333 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_rsa.pub.
2025-12-10 00:31:02.383379 | controller -> localhost | The key fingerprint is:
2025-12-10 00:31:02.383422 | controller -> localhost | SHA256:QOUQj41UI2oEKhWg55kzhiTY85bm78qtghN5+cuWnQo zuul-build-sshkey
2025-12-10 00:31:02.383463 | controller -> localhost | The key's randomart image is:
2025-12-10 00:31:02.383503 | controller -> localhost | +---[RSA 2048]----+
2025-12-10 00:31:02.383543 | controller -> localhost | |..+o. *++        |
2025-12-10 00:31:02.383584 | controller -> localhost | |o+ . + O .       |
2025-12-10 00:31:02.383624 | controller -> localhost | |*.+ o + +        |
2025-12-10 00:31:02.383663 | controller -> localhost | |++ * . .         |
2025-12-10 00:31:02.383701 | controller -> localhost | |..B.=   S        |
2025-12-10 00:31:02.383797 | controller -> localhost | |o.o*             |
2025-12-10 00:31:02.383856 | controller -> localhost | | +E..o .         |
2025-12-10 00:31:02.383900 | controller -> localhost | |o .++oo          |
2025-12-10 00:31:02.383940 | controller -> localhost | | . oB*+          |
2025-12-10 00:31:02.383985 | controller -> localhost | +----[SHA256]-----+
2025-12-10 00:31:02.384077 | controller -> localhost | ok: Runtime: 0:00:00.064761
2025-12-10 00:31:02.399114 | 
2025-12-10 00:31:02.399248 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-10 00:31:02.438661 | controller | ok
2025-12-10 00:31:02.461576 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-10 00:31:02.474341 | 
2025-12-10 00:31:02.474429 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-10 00:31:02.499648 | controller | skipping: Conditional result was False
2025-12-10 00:31:02.509233 | 
2025-12-10 00:31:02.509396 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-10 00:31:03.617259 | controller | changed
2025-12-10 00:31:03.630072 | 
2025-12-10 00:31:03.630209 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-10 00:31:04.304065 | controller | ok
2025-12-10 00:31:04.317544 | 
2025-12-10 00:31:04.317678 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-10 00:31:07.343413 | controller | changed
2025-12-10 00:31:07.351087 | 
2025-12-10 00:31:07.351178 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-10 00:31:10.371174 | controller | changed
2025-12-10 00:31:10.384527 | 
2025-12-10 00:31:10.384658 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-10 00:31:10.400496 | controller | skipping: Conditional result was False
2025-12-10 00:31:10.414387 | 
2025-12-10 00:31:10.414525 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-10 00:31:10.816907 | controller -> localhost | changed
2025-12-10 00:31:10.828545 | 
2025-12-10 00:31:10.828610 | TASK [add-build-sshkey : Add back temp key]
2025-12-10 00:31:11.117034 | controller -> localhost | Identity added: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_rsa (zuul-build-sshkey)
2025-12-10 00:31:11.117370 | controller -> localhost | ok: Runtime: 0:00:00.006405
2025-12-10 00:31:11.131061 | 
2025-12-10 00:31:11.131214 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-10 00:31:12.038545 | controller | ok
2025-12-10 00:31:12.051788 | 
2025-12-10 00:31:12.051942 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-10 00:31:12.090073 | controller | skipping: Conditional result was False
2025-12-10 00:31:12.118473 | 
2025-12-10 00:31:12.118652 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-10 00:31:12.153671 | controller | ok
2025-12-10 00:31:12.179622 | 
2025-12-10 00:31:12.179806 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-10 00:31:12.470614 | controller -> localhost | ok
2025-12-10 00:31:12.487252 | 
2025-12-10 00:31:12.487404 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-10 00:31:12.539350 | controller | ok
2025-12-10 00:31:12.562921 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-10 00:31:12.573812 | 
2025-12-10 00:31:12.573907 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-10 00:31:12.919785 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-10 00:31:12.920168 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_ecdsa.
2025-12-10 00:31:12.920237 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_ecdsa.pub.
2025-12-10 00:31:12.920304 | controller -> localhost | The key fingerprint is:
2025-12-10 00:31:12.920348 | controller -> localhost | SHA256:YLNLlgezxRP8Q5ciYIL0jmADiownlLO3dBSorwULXuQ zuul-build-sshkey
2025-12-10 00:31:12.920388 | controller -> localhost | The key's randomart image is:
2025-12-10 00:31:12.920427 | controller -> localhost | +---[ECDSA 521]---+
2025-12-10 00:31:12.920465 | controller -> localhost | |.oo.o.+o.    .   |
2025-12-10 00:31:12.920505 | controller -> localhost | |Bo.+ + .o.o o    |
2025-12-10 00:31:12.920542 | controller -> localhost | |*+B o * ++ o     |
2025-12-10 00:31:12.920579 | controller -> localhost | |oB.E o X .o      |
2025-12-10 00:31:12.920615 | controller -> localhost | |o O + * S  .     |
2025-12-10 00:31:12.920650 | controller -> localhost | | o + o o         |
2025-12-10 00:31:12.920686 | controller -> localhost | |  o   .          |
2025-12-10 00:31:12.920722 | controller -> localhost | | .               |
2025-12-10 00:31:12.920972 | controller -> localhost | |                 |
2025-12-10 00:31:12.921033 | controller -> localhost | +----[SHA256]-----+
2025-12-10 00:31:12.921156 | controller -> localhost | ok: Runtime: 0:00:00.014229
2025-12-10 00:31:12.936559 | 
2025-12-10 00:31:12.936699 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-10 00:31:12.980016 | controller | ok
2025-12-10 00:31:12.996941 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-10 00:31:13.009612 | 
2025-12-10 00:31:13.009712 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-10 00:31:13.034894 | controller | skipping: Conditional result was False
2025-12-10 00:31:13.044721 | 
2025-12-10 00:31:13.044862 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-10 00:31:14.342224 | controller | changed
2025-12-10 00:31:14.395621 | 
2025-12-10 00:31:14.395786 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-10 00:31:15.056595 | controller | ok
2025-12-10 00:31:15.069387 | 
2025-12-10 00:31:15.069520 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-10 00:31:18.185884 | controller | changed
2025-12-10 00:31:18.198194 | 
2025-12-10 00:31:18.198370 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-10 00:31:21.200860 | controller | changed
2025-12-10 00:31:21.214065 | 
2025-12-10 00:31:21.214264 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-10 00:31:21.242590 | controller | skipping: Conditional result was False
2025-12-10 00:31:21.259234 | 
2025-12-10 00:31:21.259459 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-10 00:31:21.554524 | controller -> localhost | changed
2025-12-10 00:31:21.571494 | 
2025-12-10 00:31:21.571595 | TASK [add-build-sshkey : Add back temp key]
2025-12-10 00:31:21.851609 | controller -> localhost | Identity added: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/8109bea8f6be48548e6b68be6a8bf824_id_ecdsa (zuul-build-sshkey)
2025-12-10 00:31:21.851994 | controller -> localhost | ok: Runtime: 0:00:00.013225
2025-12-10 00:31:21.868230 | 
2025-12-10 00:31:21.868422 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-10 00:31:22.575267 | controller | ok
2025-12-10 00:31:22.584863 | 
2025-12-10 00:31:22.584977 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-10 00:31:22.621116 | controller | skipping: Conditional result was False
2025-12-10 00:31:22.638859 | 
2025-12-10 00:31:22.638992 | TASK [include_role : remove-zuul-sshkey]
2025-12-10 00:31:22.665387 | controller | skipping: Conditional result was False
2025-12-10 00:31:22.675269 | 
2025-12-10 00:31:22.675370 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-10 00:31:23.351146 | controller | ok: "logs"
2025-12-10 00:31:23.351644 | controller | ok: All items complete
2025-12-10 00:31:23.351709 | 
2025-12-10 00:31:23.995601 | controller | ok: "artifacts"
2025-12-10 00:31:24.641137 | controller | ok: "docs"
2025-12-10 00:31:24.661843 | 
2025-12-10 00:31:24.662030 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-10 00:31:25.382600 | controller | changed: "logs"
2025-12-10 00:31:26.029354 | controller | changed: "artifacts"
2025-12-10 00:31:26.665373 | controller | changed: "docs"
2025-12-10 00:31:26.723334 | 
2025-12-10 00:31:26.723463 | PLAY RECAP
2025-12-10 00:31:26.723537 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-10 00:31:26.723586 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-10 00:31:26.723615 | 
2025-12-10 00:31:26.839074 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-10 00:31:26.839923 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-10 00:31:27.403293 | 
2025-12-10 00:31:27.403403 | PLAY [all]
2025-12-10 00:31:27.425162 | 
2025-12-10 00:31:27.425255 | TASK [Install binary dependencies]
2025-12-10 00:31:27.495023 | controller | ok
2025-12-10 00:31:27.514275 | 
2025-12-10 00:31:27.514360 | TASK [bindep : Include find tasks]
2025-12-10 00:31:27.555102 | controller | ok
2025-12-10 00:31:27.562836 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-10 00:31:27.569444 | 
2025-12-10 00:31:27.569508 | TASK [bindep : Look for bindep.txt]
2025-12-10 00:31:28.492872 | controller | ok
2025-12-10 00:31:28.505598 | 
2025-12-10 00:31:28.505772 | TASK [bindep : Define bindep_file fact]
2025-12-10 00:31:28.533182 | controller | skipping: Conditional result was False
2025-12-10 00:31:28.546285 | 
2025-12-10 00:31:28.546424 | TASK [bindep : Look for other-requirements.txt]
2025-12-10 00:31:29.228321 | controller | ok
2025-12-10 00:31:29.234262 | 
2025-12-10 00:31:29.234331 | TASK [bindep : Define bindep_file fact]
2025-12-10 00:31:29.269128 | controller | skipping: Conditional result was False
2025-12-10 00:31:29.275518 | 
2025-12-10 00:31:29.275588 | TASK [bindep : Look for bindep fallback file]
2025-12-10 00:31:29.309713 | controller | skipping: Conditional result was False
2025-12-10 00:31:29.315712 | 
2025-12-10 00:31:29.315789 | TASK [bindep : Define bindep_file fact]
2025-12-10 00:31:29.349548 | controller | skipping: Conditional result was False
2025-12-10 00:31:29.355306 | 
2025-12-10 00:31:29.355369 | TASK [bindep : Include bindep tasks]
2025-12-10 00:31:29.389889 | controller | skipping: Conditional result was False
2025-12-10 00:31:29.403016 | 
2025-12-10 00:31:29.403149 | TASK [bindep : Include install tasks]
2025-12-10 00:31:29.439787 | controller | skipping: Conditional result was False
2025-12-10 00:31:29.452560 | 
2025-12-10 00:31:29.452693 | LOOP [bindep : Include package tasks]
2025-12-10 00:31:29.547233 | 
2025-12-10 00:31:29.547499 | TASK [Run test-setup role]
2025-12-10 00:31:29.576156 | controller | ok
2025-12-10 00:31:29.607008 | 
2025-12-10 00:31:29.607105 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-10 00:31:30.268012 | controller | ok
2025-12-10 00:31:30.274038 | 
2025-12-10 00:31:30.274107 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-10 00:31:30.634066 | controller | skipping: Conditional result was False
2025-12-10 00:31:30.661197 | 
2025-12-10 00:31:30.661281 | PLAY RECAP
2025-12-10 00:31:30.661321 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-10 00:31:30.661341 | 
2025-12-10 00:31:30.759848 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-10 00:31:30.760672 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-10 00:31:31.295682 | 
2025-12-10 00:31:31.295825 | PLAY [controller]
2025-12-10 00:31:31.315864 | 
2025-12-10 00:31:31.315948 | TASK [Create the /root directory]
2025-12-10 00:31:32.387905 | controller | ok
2025-12-10 00:31:32.401050 | 
2025-12-10 00:31:32.401229 | TASK [Install glibc-langpack-en]
2025-12-10 00:31:40.951390 | controller | ok: Nothing to do
2025-12-10 00:31:40.966523 | 
2025-12-10 00:31:40.966672 | TASK [Ensure controller directory exists]
2025-12-10 00:31:41.781843 | controller | changed
2025-12-10 00:31:41.794385 | 
2025-12-10 00:31:41.794522 | TASK [Install container runtime]
2025-12-10 00:31:41.873601 | controller | ok
2025-12-10 00:31:41.934223 | 
2025-12-10 00:31:41.934511 | LOOP [ensure-podman : Find distribution installation]
2025-12-10 00:31:41.984404 | controller | ok: "/var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-10 00:31:42.005389 | controller | included: /var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-10 00:31:42.020338 | 
2025-12-10 00:31:42.020477 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-10 00:33:39.208089 | controller | changed
2025-12-10 00:33:39.216574 | 
2025-12-10 00:33:39.216659 | TASK [ensure-podman : Fetch podman version]
2025-12-10 00:33:40.425550 | controller | Client:       Podman Engine
2025-12-10 00:33:40.464447 | controller | Version:      4.6.2
2025-12-10 00:33:40.464504 | controller | API Version:  4.6.2
2025-12-10 00:33:40.464512 | controller | Go Version:   go1.19.12
2025-12-10 00:33:40.464531 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-10 00:33:40.464541 | controller | OS/Arch:      linux/amd64
2025-12-10 00:33:40.591260 | controller | ok: Runtime: 0:00:00.312654
2025-12-10 00:33:40.597155 | 
2025-12-10 00:33:40.597220 | TASK [ensure-podman : Print podman version installed]
2025-12-10 00:33:40.627350 | Podman version: Client:       Podman Engine
2025-12-10 00:33:40.627459 | Version:      4.6.2
2025-12-10 00:33:40.627486 | API Version:  4.6.2
2025-12-10 00:33:40.627505 | Go Version:   go1.19.12
2025-12-10 00:33:40.627523 | Built:        Mon Aug 28 19:38:31 2023
2025-12-10 00:33:40.627543 | OS/Arch:      linux/amd64
2025-12-10 00:33:40.632752 | 
2025-12-10 00:33:40.632808 | TASK [ensure-podman : Validate podman engine]
2025-12-10 00:33:40.984596 | controller | skipping: Conditional result was False
2025-12-10 00:33:40.998032 | 
2025-12-10 00:33:40.998170 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-10 00:33:41.025152 | controller | skipping: Conditional result was False
2025-12-10 00:33:41.047764 | 
2025-12-10 00:33:41.047902 | TASK [Ensure python3.8 is present]
2025-12-10 00:33:41.074867 | controller | skipping: Conditional result was False
2025-12-10 00:33:41.088170 | 
2025-12-10 00:33:41.088303 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-10 00:33:41.117692 | controller | ok
2025-12-10 00:33:41.155860 | 
2025-12-10 00:33:41.155962 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-10 00:33:44.801667 | controller | ok: Nothing to do
2025-12-10 00:33:44.814170 | 
2025-12-10 00:33:44.814304 | TASK [our-ensure-python : Also install python3-devel]
2025-12-10 00:33:59.148957 | controller | changed
2025-12-10 00:33:59.172782 | 
2025-12-10 00:33:59.173041 | TASK [Run ensure-virtualenv role]
2025-12-10 00:33:59.201225 | controller | ok
2025-12-10 00:33:59.236593 | 
2025-12-10 00:33:59.236718 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-10 00:34:00.054878 | controller | /usr/bin/virtualenv
2025-12-10 00:34:00.621271 | controller | ok: Runtime: 0:00:00.007501
2025-12-10 00:34:00.634646 | 
2025-12-10 00:34:00.634823 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-10 00:34:00.670382 | controller | skipping: Conditional result was False
2025-12-10 00:34:00.670849 | controller | ok: All items complete
2025-12-10 00:34:00.670910 | 
2025-12-10 00:34:00.706958 | 
2025-12-10 00:34:00.707164 | TASK [Find the full path of the Python interpreter]
2025-12-10 00:34:01.537043 | controller | /usr/bin/python3
2025-12-10 00:34:02.078382 | controller | ok
2025-12-10 00:34:02.091661 | 
2025-12-10 00:34:02.091841 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-10 00:34:03.942329 | controller | created virtual environment CPython3.11.0.final.0-64 in 910ms
2025-12-10 00:34:04.032046 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-10 00:34:04.032157 | 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)
2025-12-10 00:34:04.032176 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-10 00:34:04.032208 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-10 00:34:04.473026 | controller | changed
2025-12-10 00:34:04.486401 | 
2025-12-10 00:34:04.486549 | TASK [Set selinux package]
2025-12-10 00:34:04.532803 | controller | ok
2025-12-10 00:34:04.545188 | 
2025-12-10 00:34:04.545329 | TASK [Set selinux package (Fedora)]
2025-12-10 00:34:04.604380 | controller | ok
2025-12-10 00:34:04.615393 | 
2025-12-10 00:34:04.615523 | TASK [Install selinux into virtualenv]
2025-12-10 00:34:08.169092 | controller | Collecting selinux-please-lie-to-me
2025-12-10 00:34:08.234670 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-10 00:34:08.740165 | controller | Collecting setuptools<50.0.0
2025-12-10 00:34:08.745267 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-10 00:34:08.801258 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.5 MB/s eta 0:00:00
2025-12-10 00:34:08.927117 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-10 00:34:08.927363 | controller |   Attempting uninstall: setuptools
2025-12-10 00:34:08.932328 | controller |     Found existing installation: setuptools 62.6.0
2025-12-10 00:34:09.028346 | controller |     Uninstalling setuptools-62.6.0:
2025-12-10 00:34:09.044815 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-10 00:34:09.770944 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-10 00:34:09.961751 | controller |
2025-12-10 00:34:10.257282 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-10 00:34:10.257341 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-10 00:34:10.516426 | controller | ok: Runtime: 0:00:04.800521
2025-12-10 00:34:10.532190 | 
2025-12-10 00:34:10.532364 | TASK [Install pytest-forked into virtualenv]
2025-12-10 00:34:12.004948 | controller | Collecting pytest-forked
2025-12-10 00:34:12.071326 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-10 00:34:12.141355 | controller | Collecting py
2025-12-10 00:34:12.147528 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-10 00:34:12.181933 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.0 MB/s eta 0:00:00
2025-12-10 00:34:12.428839 | controller | Collecting pytest>=3.10
2025-12-10 00:34:12.435737 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-10 00:34:12.461975 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 18.7 MB/s eta 0:00:00
2025-12-10 00:34:12.537956 | controller | Collecting iniconfig>=1.0.1
2025-12-10 00:34:12.542544 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-10 00:34:12.616720 | controller | Collecting packaging>=22
2025-12-10 00:34:12.624572 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-10 00:34:12.638579 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.4 MB/s eta 0:00:00
2025-12-10 00:34:12.685624 | controller | Collecting pluggy<2,>=1.5
2025-12-10 00:34:12.691298 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-10 00:34:12.799054 | controller | Collecting pygments>=2.7.2
2025-12-10 00:34:12.805550 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-10 00:34:12.847276 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 36.3 MB/s eta 0:00:00
2025-12-10 00:34:12.979842 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-10 00:34:15.343199 | 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
2025-12-10 00:34:15.357299 | controller |
2025-12-10 00:34:15.583689 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-10 00:34:15.583746 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-10 00:34:15.923245 | controller | ok: Runtime: 0:00:04.269579
2025-12-10 00:34:15.935428 | 
2025-12-10 00:34:15.935570 | TASK [Update pip]
2025-12-10 00:34:17.337940 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-10 00:34:17.604283 | controller | Collecting pip
2025-12-10 00:34:17.682704 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-10 00:34:17.757511 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 25.7 MB/s eta 0:00:00
2025-12-10 00:34:17.863864 | controller | Installing collected packages: pip
2025-12-10 00:34:17.864189 | controller |   Attempting uninstall: pip
2025-12-10 00:34:17.869683 | controller |     Found existing installation: pip 22.2.2
2025-12-10 00:34:18.100190 | controller |     Uninstalling pip-22.2.2:
2025-12-10 00:34:18.128361 | controller |       Successfully uninstalled pip-22.2.2
2025-12-10 00:34:19.885247 | controller | Successfully installed pip-25.3
2025-12-10 00:34:20.328683 | controller | ok: Runtime: 0:00:03.349839
2025-12-10 00:34:20.342590 | 
2025-12-10 00:34:20.342933 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-10 00:34:21.212897 | controller | changed
2025-12-10 00:34:21.260135 | 
2025-12-10 00:34:21.260281 | TASK [Install ansible into virtualenv]
2025-12-10 00:34:22.581177 | controller | Processing ./src/github.com/ansible/ansible
2025-12-10 00:34:22.588394 | controller |   Installing build dependencies: started
2025-12-10 00:34:24.581952 | controller |   Installing build dependencies: finished with status 'done'
2025-12-10 00:34:24.582505 | controller |   Getting requirements to build wheel: started
2025-12-10 00:34:26.071836 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-10 00:34:26.074397 | controller |   Preparing metadata (pyproject.toml): started
2025-12-10 00:34:26.933859 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-10 00:34:26.934426 | 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.
2025-12-10 00:34:26.940110 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-10 00:34:27.632003 | controller | ERROR
2025-12-10 00:34:27.632330 | controller | {
2025-12-10 00:34:27.632393 | controller |   "delta": "0:00:05.189230",
2025-12-10 00:34:27.632435 | controller |   "end": "2025-12-10 00:34:27.108844",
2025-12-10 00:34:27.632498 | controller |   "msg": "non-zero return code",
2025-12-10 00:34:27.632556 | controller |   "rc": 1,
2025-12-10 00:34:27.632594 | controller |   "start": "2025-12-10 00:34:21.919614"
2025-12-10 00:34:27.632630 | controller | }
failure
2025-12-10 00:34:27.635536 | 
2025-12-10 00:34:27.635637 | PLAY RECAP
2025-12-10 00:34:27.635779 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-10 00:34:27.635838 | 
2025-12-10 00:34:27.774263 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-10 00:34:27.775217 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-10 00:34:28.332994 | 
2025-12-10 00:34:28.333105 | PLAY [all]
2025-12-10 00:34:28.354081 | 
2025-12-10 00:34:28.354164 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-10 00:34:30.226781 | controller | changed: non-zero return code
2025-12-10 00:34:30.239417 | 
2025-12-10 00:34:30.239607 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-10 00:34:30.266799 | controller | skipping: Conditional result was False
2025-12-10 00:34:30.279676 | 
2025-12-10 00:34:30.280051 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-10 00:34:30.321208 | 
2025-12-10 00:34:30.321448 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-10 00:34:30.360180 | 
2025-12-10 00:34:30.360434 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-10 00:34:30.386938 | controller | skipping: Conditional result was False
2025-12-10 00:34:30.399890 | 
2025-12-10 00:34:30.400042 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-10 00:34:30.438939 | 
2025-12-10 00:34:30.439218 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-10 00:34:30.466188 | controller | skipping: Conditional result was False
2025-12-10 00:34:30.478913 | 
2025-12-10 00:34:30.479061 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-10 00:34:30.505626 | controller | skipping: Conditional result was False
2025-12-10 00:34:30.518463 | 
2025-12-10 00:34:30.518599 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-10 00:34:30.545193 | controller | skipping: Conditional result was False
2025-12-10 00:34:30.591185 | 
2025-12-10 00:34:30.591290 | PLAY RECAP
2025-12-10 00:34:30.591345 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-10 00:34:30.591373 | 
2025-12-10 00:34:30.688077 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-10 00:34:30.689825 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-10 00:34:31.299702 | 
2025-12-10 00:34:31.299931 | PLAY [all:!appliance*]
2025-12-10 00:34:31.324051 | 
2025-12-10 00:34:31.324168 | TASK [unregister the node]
2025-12-10 00:34:31.679813 | controller | skipping: Conditional result was False
2025-12-10 00:34:31.687577 | 
2025-12-10 00:34:31.687679 | TASK [include_role : fetch-output]
2025-12-10 00:34:31.735978 | controller | ok
2025-12-10 00:34:31.772494 | 
2025-12-10 00:34:31.772639 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-10 00:34:31.838319 | controller | skipping: Conditional result was False
2025-12-10 00:34:31.847070 | 
2025-12-10 00:34:31.847170 | TASK [fetch-output : Set log path for single node]
2025-12-10 00:34:31.879158 | controller | ok
2025-12-10 00:34:31.886827 | 
2025-12-10 00:34:31.886923 | LOOP [fetch-output : Ensure local output dirs]
2025-12-10 00:34:32.290850 | controller -> localhost | ok: "/var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/logs"
2025-12-10 00:34:32.543932 | controller -> localhost | changed: "/var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/artifacts"
2025-12-10 00:34:32.775790 | controller -> localhost | changed: "/var/lib/zuul/builds/8109bea8f6be48548e6b68be6a8bf824/work/docs"
2025-12-10 00:34:32.794264 | 
2025-12-10 00:34:32.794386 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-10 00:34:34.987203 | controller | changed:
2025-12-10 00:34:34.987532 | controller | .d..t...... ./
2025-12-10 00:34:34.987592 | controller | cd+++++++++ controller/
2025-12-10 00:34:34.987661 | controller | changed: All items complete
2025-12-10 00:34:34.987707 | 
2025-12-10 00:34:37.051225 | controller | changed: .d..t...... ./
2025-12-10 00:34:39.128497 | controller | changed: .d..t...... ./
2025-12-10 00:34:39.148437 | 
2025-12-10 00:34:39.148521 | TASK [include_role : fetch-output-openshift]
2025-12-10 00:34:39.172788 | controller | skipping: Conditional result was False
2025-12-10 00:34:39.179024 | 
2025-12-10 00:34:39.179099 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-10 00:34:39.222651 | controller | skipping: Conditional result was False
2025-12-10 00:34:39.233940 | controller | skipping: Conditional result was False
2025-12-10 00:34:39.269653 | 
2025-12-10 00:34:39.269793 | PLAY [localhost]
2025-12-10 00:34:39.281939 | 
2025-12-10 00:34:39.281999 | TASK [Run Zuul manifest role]
2025-12-10 00:34:39.300466 | localhost | ok
2025-12-10 00:34:39.314051 | 
2025-12-10 00:34:39.314118 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-10 00:34:39.711839 | localhost | changed
2025-12-10 00:34:39.718497 | 
2025-12-10 00:34:39.718581 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-10 00:34:39.759838 | localhost | ok
2025-12-10 00:34:39.771182 | 
2025-12-10 00:34:39.771261 | TASK [Set zuul-log-path fact]
2025-12-10 00:34:39.792847 | localhost | ok
2025-12-10 00:34:39.845395 | 
2025-12-10 00:34:39.845507 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 00:34:39.883972 | localhost | ok
2025-12-10 00:34:39.892814 | 
2025-12-10 00:34:39.892885 | LOOP [Run upload-logs-swift role]
2025-12-10 00:34:39.939209 | localhost | Output suppressed because no_log was given
2025-12-10 00:34:39.964227 | 
2025-12-10 00:34:39.964295 | TASK [Set zuul-log-path fact]
2025-12-10 00:34:39.998688 | localhost | skipping: Conditional result was False
2025-12-10 00:34:40.006214 | 
2025-12-10 00:34:40.006285 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-10 00:34:40.378152 | localhost -> localhost | ok: Runtime: 0:00:00.008725
2025-12-10 00:34:40.390592 | 
2025-12-10 00:34:40.390823 | TASK [upload-logs-swift : Upload logs to swift]