2025-10-02 00:12:17.961775 | Job console starting...
2025-10-02 00:12:17.972286 | Updating repositories
2025-10-02 00:12:18.087992 | Preparing job workspace
2025-10-02 00:12:21.837918 | Running Ansible setup...
2025-10-02 00:12:27.581892 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-02 00:12:28.183836 | 
2025-10-02 00:12:28.183951 | PLAY [localhost]
2025-10-02 00:12:28.198306 | 
2025-10-02 00:12:28.198380 | TASK [Gathering Facts]
2025-10-02 00:12:29.149509 | localhost | ok
2025-10-02 00:12:29.180157 | 
2025-10-02 00:12:29.180380 | TASK [Setup log path fact]
2025-10-02 00:12:29.200959 | localhost | ok
2025-10-02 00:12:29.217695 | 
2025-10-02 00:12:29.217791 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 00:12:29.247467 | localhost | ok
2025-10-02 00:12:29.258735 | 
2025-10-02 00:12:29.258826 | TASK [emit-job-header : Print job information]
2025-10-02 00:12:29.288342 | # Job Information
2025-10-02 00:12:29.288490 | Ansible Version: 2.15.12
2025-10-02 00:12:29.288532 | Job: ansible-test-sanity-docker-devel
2025-10-02 00:12:29.288561 | Pipeline: periodic
2025-10-02 00:12:29.288587 | Executor: ze02.softwarefactory-project.io
2025-10-02 00:12:29.288612 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-02 00:12:29.288643 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/1b0/ansible/1b0b332de059448f9e61f83d6d4aec9d/
2025-10-02 00:12:29.288694 | Event ID: dc6de0c9c3c649899b29042e956f2ac8
2025-10-02 00:12:29.293736 | 
2025-10-02 00:12:29.293824 | LOOP [emit-job-header : Print node information]
2025-10-02 00:12:29.391773 | localhost | ok:
2025-10-02 00:12:29.392172 | localhost | # Node Information
2025-10-02 00:12:29.392233 | localhost | Inventory Hostname: controller
2025-10-02 00:12:29.392276 | localhost | Hostname: ip-172-16-163-165
2025-10-02 00:12:29.392317 | localhost | Username: zuul-worker
2025-10-02 00:12:29.392363 | localhost | Distro: Fedora 37
2025-10-02 00:12:29.392403 | localhost | Provider: ansible-us-east-2
2025-10-02 00:12:29.392441 | localhost | Region: us-east-2
2025-10-02 00:12:29.392480 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-02 00:12:29.392517 | localhost | Product Name: t3.small
2025-10-02 00:12:29.392555 | localhost | Interface IP: 18.118.114.163
2025-10-02 00:12:29.416226 | 
2025-10-02 00:12:29.416365 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-02 00:12:29.800153 | localhost -> localhost | changed
2025-10-02 00:12:29.811459 | 
2025-10-02 00:12:29.811596 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-02 00:12:30.661734 | localhost -> localhost | changed
2025-10-02 00:12:30.681232 | 
2025-10-02 00:12:30.681292 | PLAY [all:!appliance*]
2025-10-02 00:12:30.696344 | 
2025-10-02 00:12:30.696405 | TASK [include_role : start-zuul-console]
2025-10-02 00:12:30.716843 | controller | ok
2025-10-02 00:12:30.729766 | 
2025-10-02 00:12:30.729825 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-02 00:12:31.406008 | controller | ok
2025-10-02 00:12:31.427767 | 
2025-10-02 00:12:31.427909 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-02 00:12:33.087853 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-02 00:12:33.101934 | 
2025-10-02 00:12:33.102127 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-02 00:12:33.254588 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.262954 | 
2025-10-02 00:12:33.263042 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-02 00:12:33.299415 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.308190 | 
2025-10-02 00:12:33.308280 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-02 00:12:33.333484 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.342296 | 
2025-10-02 00:12:33.342385 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-02 00:12:33.368023 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.376264 | 
2025-10-02 00:12:33.376388 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-02 00:12:33.401859 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.410263 | 
2025-10-02 00:12:33.410421 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-02 00:12:33.436708 | controller | skipping: Conditional result was False
2025-10-02 00:12:33.455008 | 
2025-10-02 00:12:33.455147 | TASK [Disable Fedora Modular]
2025-10-02 00:12:34.197265 | controller | changed
2025-10-02 00:12:34.209428 | 
2025-10-02 00:12:34.209559 | TASK [Enable EPEL]
2025-10-02 00:12:34.235880 | controller | skipping: Conditional result was False
2025-10-02 00:12:34.243955 | 
2025-10-02 00:12:34.244063 | TASK [Register the RHEL node]
2025-10-02 00:12:34.404258 | 
2025-10-02 00:12:34.404530 | TASK [Show the subscription-manager status]
2025-10-02 00:12:34.551737 | controller | skipping: Conditional result was False
2025-10-02 00:12:34.605981 | 
2025-10-02 00:12:34.606121 | TASK [Enable EPEL on RHEL]
2025-10-02 00:12:34.752489 | controller | skipping: Conditional result was False
2025-10-02 00:12:34.766588 | 
2025-10-02 00:12:34.766770 | TASK [Install git and tox]
2025-10-02 00:14:10.125907 | controller | changed
2025-10-02 00:14:10.139791 | 
2025-10-02 00:14:10.139989 | TASK [include_role : prepare-workspace]
2025-10-02 00:14:10.177878 | controller | ok
2025-10-02 00:14:10.213836 | 
2025-10-02 00:14:10.213942 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-02 00:14:10.749472 | controller | ok
2025-10-02 00:14:10.761546 | 
2025-10-02 00:14:10.761630 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-02 00:14:23.009330 | controller | Output suppressed because no_log was given
2025-10-02 00:14:23.019261 | 
2025-10-02 00:14:23.019324 | TASK [include_role : prepare-workspace-openshift]
2025-10-02 00:14:23.044720 | controller | skipping: Conditional result was False
2025-10-02 00:14:23.068209 | 
2025-10-02 00:14:23.068276 | PLAY [all:!appliance]
2025-10-02 00:14:23.084416 | 
2025-10-02 00:14:23.084514 | TASK [Run add-build-sshkey role (RSA)]
2025-10-02 00:14:23.116944 | controller | ok
2025-10-02 00:14:23.178716 | 
2025-10-02 00:14:23.178873 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-02 00:14:23.470183 | controller -> localhost | ok
2025-10-02 00:14:23.484900 | 
2025-10-02 00:14:23.485066 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-02 00:14:23.526944 | controller | ok
2025-10-02 00:14:23.555089 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-02 00:14:23.563861 | 
2025-10-02 00:14:23.563952 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-02 00:14:24.052411 | controller -> localhost | Generating public/private rsa key pair.
2025-10-02 00:14:24.052843 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_rsa.
2025-10-02 00:14:24.052911 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_rsa.pub.
2025-10-02 00:14:24.052961 | controller -> localhost | The key fingerprint is:
2025-10-02 00:14:24.053008 | controller -> localhost | SHA256:sqHOk7jG/6+ASREWPcpbAMY5R6Z+cW/ytt/vghN0ae0 zuul-build-sshkey
2025-10-02 00:14:24.053054 | controller -> localhost | The key's randomart image is:
2025-10-02 00:14:24.053099 | controller -> localhost | +---[RSA 2048]----+
2025-10-02 00:14:24.053142 | controller -> localhost | |oo*=             |
2025-10-02 00:14:24.053186 | controller -> localhost | |.=+oo            |
2025-10-02 00:14:24.053229 | controller -> localhost | | o++ o      o    |
2025-10-02 00:14:24.053271 | controller -> localhost | |. o.+ .  . + .   |
2025-10-02 00:14:24.053313 | controller -> localhost | | ..+ .ooS o .    |
2025-10-02 00:14:24.053380 | controller -> localhost | | .oo .++ .   E   |
2025-10-02 00:14:24.053435 | controller -> localhost | | .o.o..o  o      |
2025-10-02 00:14:24.053480 | controller -> localhost | |  +oo.. .o..     |
2025-10-02 00:14:24.053525 | controller -> localhost | | ..o+oo+o...+o   |
2025-10-02 00:14:24.053573 | controller -> localhost | +----[SHA256]-----+
2025-10-02 00:14:24.053713 | controller -> localhost | ok: Runtime: 0:00:00.041892
2025-10-02 00:14:24.069529 | 
2025-10-02 00:14:24.069720 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-02 00:14:24.105263 | controller | ok
2025-10-02 00:14:24.128962 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-02 00:14:24.142013 | 
2025-10-02 00:14:24.142110 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-02 00:14:24.169569 | controller | skipping: Conditional result was False
2025-10-02 00:14:24.178458 | 
2025-10-02 00:14:24.178544 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-02 00:14:24.754857 | controller | changed
2025-10-02 00:14:24.763299 | 
2025-10-02 00:14:24.763541 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-02 00:14:25.115166 | controller | ok
2025-10-02 00:14:25.123299 | 
2025-10-02 00:14:25.123522 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-02 00:14:26.371559 | controller | changed
2025-10-02 00:14:26.377116 | 
2025-10-02 00:14:26.377182 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-02 00:14:27.645955 | controller | changed
2025-10-02 00:14:27.658286 | 
2025-10-02 00:14:27.658458 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-02 00:14:27.685816 | controller | skipping: Conditional result was False
2025-10-02 00:14:27.700839 | 
2025-10-02 00:14:27.700989 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-02 00:14:28.115613 | controller -> localhost | changed
2025-10-02 00:14:28.126475 | 
2025-10-02 00:14:28.126571 | TASK [add-build-sshkey : Add back temp key]
2025-10-02 00:14:28.469903 | controller -> localhost | Identity added: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_rsa (zuul-build-sshkey)
2025-10-02 00:14:28.470275 | controller -> localhost | ok: Runtime: 0:00:00.011402
2025-10-02 00:14:28.484413 | 
2025-10-02 00:14:28.484552 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-02 00:14:29.000297 | controller | ok
2025-10-02 00:14:29.009709 | 
2025-10-02 00:14:29.009810 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-02 00:14:29.045555 | controller | skipping: Conditional result was False
2025-10-02 00:14:29.060568 | 
2025-10-02 00:14:29.060685 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-02 00:14:29.094546 | controller | ok
2025-10-02 00:14:29.115936 | 
2025-10-02 00:14:29.116084 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-02 00:14:29.398646 | controller -> localhost | ok
2025-10-02 00:14:29.422459 | 
2025-10-02 00:14:29.422600 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-02 00:14:29.460220 | controller | ok
2025-10-02 00:14:29.482847 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-02 00:14:29.490401 | 
2025-10-02 00:14:29.490485 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-02 00:14:29.863060 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-02 00:14:29.863425 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_ecdsa.
2025-10-02 00:14:29.863487 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_ecdsa.pub.
2025-10-02 00:14:29.863548 | controller -> localhost | The key fingerprint is:
2025-10-02 00:14:29.863593 | controller -> localhost | SHA256:LQuS4kalNjjefb0UjClw3iehfsQMVZKG/PU+Xm1rIkU zuul-build-sshkey
2025-10-02 00:14:29.863635 | controller -> localhost | The key's randomart image is:
2025-10-02 00:14:29.863714 | controller -> localhost | +---[ECDSA 521]---+
2025-10-02 00:14:29.863760 | controller -> localhost | |    . .oo.       |
2025-10-02 00:14:29.863801 | controller -> localhost | |     o.o..       |
2025-10-02 00:14:29.863840 | controller -> localhost | |   ..oo.. .      |
2025-10-02 00:14:29.863879 | controller -> localhost | | . o+.*.=. . E   |
2025-10-02 00:14:29.863918 | controller -> localhost | |o * o+.OS+o . .  |
2025-10-02 00:14:29.863958 | controller -> localhost | |.=.oo.o.+o.o o o |
2025-10-02 00:14:29.863996 | controller -> localhost | | .o. o o.o. + . .|
2025-10-02 00:14:29.864034 | controller -> localhost | | .    o . .o . o |
2025-10-02 00:14:29.864073 | controller -> localhost | |         .  . o  |
2025-10-02 00:14:29.864111 | controller -> localhost | +----[SHA256]-----+
2025-10-02 00:14:29.864207 | controller -> localhost | ok: Runtime: 0:00:00.016683
2025-10-02 00:14:29.887106 | 
2025-10-02 00:14:29.887242 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-02 00:14:29.924637 | controller | ok
2025-10-02 00:14:29.941830 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-02 00:14:29.954533 | 
2025-10-02 00:14:29.954615 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-02 00:14:29.979512 | controller | skipping: Conditional result was False
2025-10-02 00:14:29.988234 | 
2025-10-02 00:14:29.988321 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-02 00:14:30.452019 | controller | changed
2025-10-02 00:14:30.464214 | 
2025-10-02 00:14:30.464356 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-02 00:14:30.807047 | controller | ok
2025-10-02 00:14:30.814910 | 
2025-10-02 00:14:30.815011 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-02 00:14:32.084473 | controller | changed
2025-10-02 00:14:32.097017 | 
2025-10-02 00:14:32.097157 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-02 00:14:33.362275 | controller | changed
2025-10-02 00:14:33.374868 | 
2025-10-02 00:14:33.375032 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-02 00:14:33.402336 | controller | skipping: Conditional result was False
2025-10-02 00:14:33.415516 | 
2025-10-02 00:14:33.415773 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-02 00:14:33.668305 | controller -> localhost | changed
2025-10-02 00:14:33.692636 | 
2025-10-02 00:14:33.692863 | TASK [add-build-sshkey : Add back temp key]
2025-10-02 00:14:34.017604 | controller -> localhost | Identity added: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/1b0b332de059448f9e61f83d6d4aec9d_id_ecdsa (zuul-build-sshkey)
2025-10-02 00:14:34.018250 | controller -> localhost | ok: Runtime: 0:00:00.009413
2025-10-02 00:14:34.038282 | 
2025-10-02 00:14:34.038506 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-02 00:14:34.386056 | controller | ok
2025-10-02 00:14:34.397546 | 
2025-10-02 00:14:34.397735 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-02 00:14:34.434815 | controller | skipping: Conditional result was False
2025-10-02 00:14:34.458778 | 
2025-10-02 00:14:34.458940 | TASK [include_role : remove-zuul-sshkey]
2025-10-02 00:14:34.485735 | controller | skipping: Conditional result was False
2025-10-02 00:14:34.503472 | 
2025-10-02 00:14:34.503657 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 00:14:34.885985 | controller | ok: "logs"
2025-10-02 00:14:34.886228 | controller | ok: All items complete
2025-10-02 00:14:34.886262 | 
2025-10-02 00:14:35.125124 | controller | ok: "artifacts"
2025-10-02 00:14:35.396078 | controller | ok: "docs"
2025-10-02 00:14:35.402507 | 
2025-10-02 00:14:35.402580 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 00:14:35.740615 | controller | changed: "logs"
2025-10-02 00:14:36.025716 | controller | changed: "artifacts"
2025-10-02 00:14:36.316291 | controller | changed: "docs"
2025-10-02 00:14:36.375246 | 
2025-10-02 00:14:36.375366 | PLAY RECAP
2025-10-02 00:14:36.375426 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-02 00:14:36.375465 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 00:14:36.375493 | 
2025-10-02 00:14:36.494526 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-02 00:14:36.496964 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 00:14:37.106193 | 
2025-10-02 00:14:37.106299 | PLAY [all]
2025-10-02 00:14:37.128040 | 
2025-10-02 00:14:37.128145 | TASK [Install binary dependencies]
2025-10-02 00:14:37.200452 | controller | ok
2025-10-02 00:14:37.226872 | 
2025-10-02 00:14:37.227002 | TASK [bindep : Include find tasks]
2025-10-02 00:14:37.258694 | controller | ok
2025-10-02 00:14:37.269217 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-02 00:14:37.277759 | 
2025-10-02 00:14:37.277846 | TASK [bindep : Look for bindep.txt]
2025-10-02 00:14:37.772771 | controller | ok
2025-10-02 00:14:37.786046 | 
2025-10-02 00:14:37.786206 | TASK [bindep : Define bindep_file fact]
2025-10-02 00:14:37.802970 | controller | skipping: Conditional result was False
2025-10-02 00:14:37.816586 | 
2025-10-02 00:14:37.816798 | TASK [bindep : Look for other-requirements.txt]
2025-10-02 00:14:38.121286 | controller | ok
2025-10-02 00:14:38.133308 | 
2025-10-02 00:14:38.133485 | TASK [bindep : Define bindep_file fact]
2025-10-02 00:14:38.170649 | controller | skipping: Conditional result was False
2025-10-02 00:14:38.183797 | 
2025-10-02 00:14:38.183955 | TASK [bindep : Look for bindep fallback file]
2025-10-02 00:14:38.221230 | controller | skipping: Conditional result was False
2025-10-02 00:14:38.233785 | 
2025-10-02 00:14:38.233957 | TASK [bindep : Define bindep_file fact]
2025-10-02 00:14:38.271640 | controller | skipping: Conditional result was False
2025-10-02 00:14:38.284411 | 
2025-10-02 00:14:38.284602 | TASK [bindep : Include bindep tasks]
2025-10-02 00:14:38.321077 | controller | skipping: Conditional result was False
2025-10-02 00:14:38.336968 | 
2025-10-02 00:14:38.337162 | TASK [bindep : Include install tasks]
2025-10-02 00:14:38.374474 | controller | skipping: Conditional result was False
2025-10-02 00:14:38.388055 | 
2025-10-02 00:14:38.388243 | LOOP [bindep : Include package tasks]
2025-10-02 00:14:38.470322 | 
2025-10-02 00:14:38.470597 | TASK [Run test-setup role]
2025-10-02 00:14:38.497782 | controller | ok
2025-10-02 00:14:38.529319 | 
2025-10-02 00:14:38.529489 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-02 00:14:38.832115 | controller | ok
2025-10-02 00:14:38.845076 | 
2025-10-02 00:14:38.845575 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-02 00:14:39.000334 | controller | skipping: Conditional result was False
2025-10-02 00:14:39.052926 | 
2025-10-02 00:14:39.053124 | PLAY RECAP
2025-10-02 00:14:39.053190 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-02 00:14:39.053219 | 
2025-10-02 00:14:39.166798 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 00:14:39.167640 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-02 00:14:39.741539 | 
2025-10-02 00:14:39.741657 | PLAY [controller]
2025-10-02 00:14:39.760460 | 
2025-10-02 00:14:39.760536 | TASK [Create the /root directory]
2025-10-02 00:14:40.521316 | controller | ok
2025-10-02 00:14:40.533360 | 
2025-10-02 00:14:40.533512 | TASK [Install glibc-langpack-en]
2025-10-02 00:14:48.689697 | controller | ok: Nothing to do
2025-10-02 00:14:48.701281 | 
2025-10-02 00:14:48.701430 | TASK [Ensure controller directory exists]
2025-10-02 00:14:49.147859 | controller | changed
2025-10-02 00:14:49.159768 | 
2025-10-02 00:14:49.159925 | TASK [Install container runtime]
2025-10-02 00:14:49.239370 | controller | ok
2025-10-02 00:14:49.301148 | 
2025-10-02 00:14:49.301301 | LOOP [ensure-podman : Find distribution installation]
2025-10-02 00:14:49.343515 | controller | ok: "/var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-02 00:14:49.352831 | controller | included: /var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-02 00:14:49.358997 | 
2025-10-02 00:14:49.359061 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-02 00:16:08.269782 | controller | changed
2025-10-02 00:16:08.285465 | 
2025-10-02 00:16:08.285710 | TASK [ensure-podman : Fetch podman version]
2025-10-02 00:16:08.979036 | controller | Client:       Podman Engine
2025-10-02 00:16:09.007518 | controller | Version:      4.6.2
2025-10-02 00:16:09.007568 | controller | API Version:  4.6.2
2025-10-02 00:16:09.007579 | controller | Go Version:   go1.19.12
2025-10-02 00:16:09.007627 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-02 00:16:09.007711 | controller | OS/Arch:      linux/amd64
2025-10-02 00:16:09.434940 | controller | ok: Runtime: 0:00:00.185912
2025-10-02 00:16:09.448899 | 
2025-10-02 00:16:09.449050 | TASK [ensure-podman : Print podman version installed]
2025-10-02 00:16:09.492608 | Podman version: Client:       Podman Engine
2025-10-02 00:16:09.493077 | Version:      4.6.2
2025-10-02 00:16:09.493196 | API Version:  4.6.2
2025-10-02 00:16:09.493257 | Go Version:   go1.19.12
2025-10-02 00:16:09.493300 | Built:        Mon Aug 28 19:38:31 2023
2025-10-02 00:16:09.493342 | OS/Arch:      linux/amd64
2025-10-02 00:16:09.509186 | 
2025-10-02 00:16:09.510000 | TASK [ensure-podman : Validate podman engine]
2025-10-02 00:16:09.652650 | controller | skipping: Conditional result was False
2025-10-02 00:16:09.670130 | 
2025-10-02 00:16:09.670300 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-02 00:16:09.698688 | controller | skipping: Conditional result was False
2025-10-02 00:16:09.723038 | 
2025-10-02 00:16:09.723187 | TASK [Ensure python3.8 is present]
2025-10-02 00:16:09.750320 | controller | skipping: Conditional result was False
2025-10-02 00:16:09.759262 | 
2025-10-02 00:16:09.759373 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-02 00:16:09.792959 | controller | ok
2025-10-02 00:16:09.818875 | 
2025-10-02 00:16:09.819001 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-02 00:16:13.486603 | controller | ok: Nothing to do
2025-10-02 00:16:13.494472 | 
2025-10-02 00:16:13.494558 | TASK [our-ensure-python : Also install python3-devel]
2025-10-02 00:16:26.560943 | controller | changed
2025-10-02 00:16:26.570866 | 
2025-10-02 00:16:26.570935 | TASK [Run ensure-virtualenv role]
2025-10-02 00:16:26.599501 | controller | ok
2025-10-02 00:16:26.639166 | 
2025-10-02 00:16:26.639288 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-02 00:16:27.017935 | controller | /usr/bin/virtualenv
2025-10-02 00:16:27.272538 | controller | ok: Runtime: 0:00:00.004570
2025-10-02 00:16:27.280937 | 
2025-10-02 00:16:27.281024 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-02 00:16:27.312616 | controller | skipping: Conditional result was False
2025-10-02 00:16:27.313067 | controller | ok: All items complete
2025-10-02 00:16:27.313127 | 
2025-10-02 00:16:27.339080 | 
2025-10-02 00:16:27.339261 | TASK [Find the full path of the Python interpreter]
2025-10-02 00:16:27.771298 | controller | /usr/bin/python3
2025-10-02 00:16:27.978730 | controller | ok
2025-10-02 00:16:27.990101 | 
2025-10-02 00:16:27.990233 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-02 00:16:29.413610 | controller | created virtual environment CPython3.11.0.final.0-64 in 785ms
2025-10-02 00:16:29.467136 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-02 00:16:29.467193 | 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-worker/.local/share/virtualenv)
2025-10-02 00:16:29.467209 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-02 00:16:29.467230 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-02 00:16:29.643449 | controller | changed
2025-10-02 00:16:29.658332 | 
2025-10-02 00:16:29.658623 | TASK [Set selinux package]
2025-10-02 00:16:29.698072 | controller | ok
2025-10-02 00:16:29.709369 | 
2025-10-02 00:16:29.709503 | TASK [Set selinux package (Fedora)]
2025-10-02 00:16:29.761232 | controller | ok
2025-10-02 00:16:29.772264 | 
2025-10-02 00:16:29.772401 | TASK [Install selinux into virtualenv]
2025-10-02 00:16:32.378729 | controller | Collecting selinux-please-lie-to-me
2025-10-02 00:16:32.471173 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-02 00:16:33.001696 | controller | Collecting setuptools<50.0.0
2025-10-02 00:16:33.022174 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-02 00:16:33.105117 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 10.2 MB/s eta 0:00:00
2025-10-02 00:16:33.258267 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-02 00:16:33.258705 | controller |   Attempting uninstall: setuptools
2025-10-02 00:16:33.263626 | controller |     Found existing installation: setuptools 62.6.0
2025-10-02 00:16:33.376772 | controller |     Uninstalling setuptools-62.6.0:
2025-10-02 00:16:33.391971 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-02 00:16:34.155517 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-02 00:16:34.372453 | controller |
2025-10-02 00:16:34.592795 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-02 00:16:34.592848 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-02 00:16:34.913481 | controller | ok: Runtime: 0:00:04.336089
2025-10-02 00:16:34.925985 | 
2025-10-02 00:16:34.926138 | TASK [Install pytest-forked into virtualenv]
2025-10-02 00:16:36.140411 | controller | Collecting pytest-forked
2025-10-02 00:16:36.226940 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-02 00:16:36.284999 | controller | Collecting py
2025-10-02 00:16:36.297627 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-02 00:16:36.328650 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.6 MB/s eta 0:00:00
2025-10-02 00:16:36.504514 | controller | Collecting pytest>=3.10
2025-10-02 00:16:36.517430 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-02 00:16:36.554726 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 10.8 MB/s eta 0:00:00
2025-10-02 00:16:36.609457 | controller | Collecting iniconfig>=1
2025-10-02 00:16:36.621717 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-02 00:16:36.689275 | controller | Collecting packaging>=20
2025-10-02 00:16:36.701600 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-02 00:16:36.710997 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.7 MB/s eta 0:00:00
2025-10-02 00:16:36.758031 | controller | Collecting pluggy<2,>=1.5
2025-10-02 00:16:36.770524 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-02 00:16:36.847857 | controller | Collecting pygments>=2.7.2
2025-10-02 00:16:36.860720 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-02 00:16:36.889186 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 49.9 MB/s eta 0:00:00
2025-10-02 00:16:37.019608 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-02 00:16:39.313521 | controller | Successfully installed iniconfig-2.1.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-10-02 00:16:39.334186 | controller |
2025-10-02 00:16:39.520527 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-02 00:16:39.520580 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-02 00:16:39.593710 | controller | ok: Runtime: 0:00:04.115373
2025-10-02 00:16:39.599232 | 
2025-10-02 00:16:39.599306 | TASK [Update pip]
2025-10-02 00:16:40.665155 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-02 00:16:40.906368 | controller | Collecting pip
2025-10-02 00:16:40.997916 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-02 00:16:41.157748 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 11.2 MB/s eta 0:00:00
2025-10-02 00:16:41.287689 | controller | Installing collected packages: pip
2025-10-02 00:16:41.287989 | controller |   Attempting uninstall: pip
2025-10-02 00:16:41.292526 | controller |     Found existing installation: pip 22.2.2
2025-10-02 00:16:41.561927 | controller |     Uninstalling pip-22.2.2:
2025-10-02 00:16:41.610801 | controller |       Successfully uninstalled pip-22.2.2
2025-10-02 00:16:43.363887 | controller | Successfully installed pip-25.2
2025-10-02 00:16:43.740312 | controller | ok: Runtime: 0:00:03.486706
2025-10-02 00:16:43.748025 | 
2025-10-02 00:16:43.748113 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-02 00:16:44.275247 | controller | changed
2025-10-02 00:16:44.288511 | 
2025-10-02 00:16:44.288749 | TASK [Install ansible into virtualenv]
2025-10-02 00:16:45.366270 | controller | Processing ./src/github.com/ansible/ansible
2025-10-02 00:16:45.372938 | controller |   Installing build dependencies: started
2025-10-02 00:16:47.317658 | controller |   Installing build dependencies: finished with status 'done'
2025-10-02 00:16:47.318877 | controller |   Getting requirements to build wheel: started
2025-10-02 00:16:48.925880 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-02 00:16:49.854649 | controller |   Preparing metadata (pyproject.toml): started
2025-10-02 00:16:49.854703 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-02 00:16:49.859570 | 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-10-02 00:16:49.864360 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-02 00:16:50.454157 | controller | ERROR
2025-10-02 00:16:50.454449 | controller | {
2025-10-02 00:16:50.454512 | controller |   "delta": "0:00:05.279907",
2025-10-02 00:16:50.454554 | controller |   "end": "2025-10-02 00:16:50.011050",
2025-10-02 00:16:50.454593 | controller |   "msg": "non-zero return code",
2025-10-02 00:16:50.454647 | controller |   "rc": 1,
2025-10-02 00:16:50.454729 | controller |   "start": "2025-10-02 00:16:44.731143"
2025-10-02 00:16:50.454768 | controller | }
failure
2025-10-02 00:16:50.457151 | 
2025-10-02 00:16:50.457243 | PLAY RECAP
2025-10-02 00:16:50.457322 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-02 00:16:50.457366 | 
2025-10-02 00:16:50.584404 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-02 00:16:50.586635 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 00:16:51.242103 | 
2025-10-02 00:16:51.242223 | PLAY [all]
2025-10-02 00:16:51.262660 | 
2025-10-02 00:16:51.262789 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-02 00:16:52.026499 | controller | changed: non-zero return code
2025-10-02 00:16:52.039659 | 
2025-10-02 00:16:52.039936 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-02 00:16:52.068294 | controller | skipping: Conditional result was False
2025-10-02 00:16:52.083229 | 
2025-10-02 00:16:52.083437 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-02 00:16:52.126121 | 
2025-10-02 00:16:52.126419 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-02 00:16:52.166982 | 
2025-10-02 00:16:52.167256 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-02 00:16:52.194387 | controller | skipping: Conditional result was False
2025-10-02 00:16:52.207562 | 
2025-10-02 00:16:52.207839 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-02 00:16:52.251045 | 
2025-10-02 00:16:52.251316 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-02 00:16:52.277889 | controller | skipping: Conditional result was False
2025-10-02 00:16:52.290552 | 
2025-10-02 00:16:52.290764 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-02 00:16:52.317812 | controller | skipping: Conditional result was False
2025-10-02 00:16:52.330456 | 
2025-10-02 00:16:52.330609 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-02 00:16:52.357465 | controller | skipping: Conditional result was False
2025-10-02 00:16:52.405185 | 
2025-10-02 00:16:52.405297 | PLAY RECAP
2025-10-02 00:16:52.405353 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-02 00:16:52.405383 | 
2025-10-02 00:16:52.500332 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 00:16:52.502059 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-02 00:16:53.074139 | 
2025-10-02 00:16:53.074258 | PLAY [all:!appliance*]
2025-10-02 00:16:53.094683 | 
2025-10-02 00:16:53.094785 | TASK [unregister the node]
2025-10-02 00:16:53.230110 | controller | skipping: Conditional result was False
2025-10-02 00:16:53.242480 | 
2025-10-02 00:16:53.242641 | TASK [include_role : fetch-output]
2025-10-02 00:16:53.291619 | controller | ok
2025-10-02 00:16:53.328848 | 
2025-10-02 00:16:53.328988 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-02 00:16:53.405476 | controller | skipping: Conditional result was False
2025-10-02 00:16:53.413315 | 
2025-10-02 00:16:53.413406 | TASK [fetch-output : Set log path for single node]
2025-10-02 00:16:53.465509 | controller | ok
2025-10-02 00:16:53.472977 | 
2025-10-02 00:16:53.473064 | LOOP [fetch-output : Ensure local output dirs]
2025-10-02 00:16:53.879629 | controller -> localhost | ok: "/var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/logs"
2025-10-02 00:16:54.137684 | controller -> localhost | changed: "/var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/artifacts"
2025-10-02 00:16:54.396509 | controller -> localhost | changed: "/var/lib/zuul/builds/1b0b332de059448f9e61f83d6d4aec9d/work/docs"
2025-10-02 00:16:54.411545 | 
2025-10-02 00:16:54.411685 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-02 00:16:55.694388 | controller | changed:
2025-10-02 00:16:55.694832 | controller | .d..t...... ./
2025-10-02 00:16:55.694925 | controller | cd+++++++++ controller/
2025-10-02 00:16:55.695230 | controller | changed: All items complete
2025-10-02 00:16:55.695319 | 
2025-10-02 00:16:56.755221 | controller | changed: .d..t...... ./
2025-10-02 00:16:57.849895 | controller | changed: .d..t...... ./
2025-10-02 00:16:57.882717 | 
2025-10-02 00:16:57.882920 | TASK [include_role : fetch-output-openshift]
2025-10-02 00:16:57.911489 | controller | skipping: Conditional result was False
2025-10-02 00:16:57.920783 | 
2025-10-02 00:16:57.920883 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-02 00:16:57.954872 | controller | skipping: Conditional result was False
2025-10-02 00:16:57.968494 | controller | skipping: Conditional result was False
2025-10-02 00:16:58.014997 | 
2025-10-02 00:16:58.015209 | PLAY [localhost]
2025-10-02 00:16:58.033048 | 
2025-10-02 00:16:58.033168 | TASK [Run Zuul manifest role]
2025-10-02 00:16:58.055428 | localhost | ok
2025-10-02 00:16:58.075013 | 
2025-10-02 00:16:58.075136 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-02 00:16:58.487427 | localhost | changed
2025-10-02 00:16:58.497192 | 
2025-10-02 00:16:58.497326 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-02 00:16:58.533299 | localhost | ok
2025-10-02 00:16:58.551029 | 
2025-10-02 00:16:58.551176 | TASK [Set zuul-log-path fact]
2025-10-02 00:16:58.576618 | localhost | ok
2025-10-02 00:16:58.600747 | 
2025-10-02 00:16:58.600869 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 00:16:58.631792 | localhost | ok
2025-10-02 00:16:58.645092 | 
2025-10-02 00:16:58.645190 | LOOP [Run upload-logs-swift role]
2025-10-02 00:16:58.672468 | localhost | Output suppressed because no_log was given
2025-10-02 00:16:58.706826 | 
2025-10-02 00:16:58.706927 | TASK [Set zuul-log-path fact]
2025-10-02 00:16:58.732276 | localhost | skipping: Conditional result was False
2025-10-02 00:16:58.739051 | 
2025-10-02 00:16:58.739140 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-02 00:16:59.124225 | localhost -> localhost | ok: Runtime: 0:00:00.008361
2025-10-02 00:16:59.135240 | 
2025-10-02 00:16:59.135374 | TASK [upload-logs-swift : Upload logs to swift]