2025-10-17 00:06:40.551284 | Job console starting...
2025-10-17 00:06:40.563953 | Updating repositories
2025-10-17 00:06:42.416433 | Preparing job workspace
2025-10-17 00:06:52.867864 | Running Ansible setup...
2025-10-17 00:06:58.981288 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-17 00:06:59.653992 | 
2025-10-17 00:06:59.654117 | PLAY [localhost]
2025-10-17 00:06:59.667878 | 
2025-10-17 00:06:59.667992 | TASK [Gathering Facts]
2025-10-17 00:07:00.708707 | localhost | ok
2025-10-17 00:07:00.733800 | 
2025-10-17 00:07:00.733934 | TASK [Setup log path fact]
2025-10-17 00:07:00.756388 | localhost | ok
2025-10-17 00:07:00.770288 | 
2025-10-17 00:07:00.770405 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-17 00:07:00.805713 | localhost | ok
2025-10-17 00:07:00.814479 | 
2025-10-17 00:07:00.814596 | TASK [emit-job-header : Print job information]
2025-10-17 00:07:00.842994 | # Job Information
2025-10-17 00:07:00.843150 | Ansible Version: 2.15.12
2025-10-17 00:07:00.843182 | Job: ansible-test-sanity-docker-milestone
2025-10-17 00:07:00.843204 | Pipeline: periodic
2025-10-17 00:07:00.843225 | Executor: ze02.softwarefactory-project.io
2025-10-17 00:07:00.843243 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-17 00:07:00.843265 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b7b/ansible/b7bfed213b19489b8a30c32b88daeb2c/
2025-10-17 00:07:00.843285 | Event ID: b03b4735f0864a5dad6a574e941e5c88
2025-10-17 00:07:00.847159 | 
2025-10-17 00:07:00.847224 | LOOP [emit-job-header : Print node information]
2025-10-17 00:07:00.945836 | localhost | ok:
2025-10-17 00:07:00.946032 | localhost | # Node Information
2025-10-17 00:07:00.946191 | localhost | Inventory Hostname: controller
2025-10-17 00:07:00.946214 | localhost | Hostname: ip-172-16-119-174
2025-10-17 00:07:00.946232 | localhost | Username: zuul-worker
2025-10-17 00:07:00.946253 | localhost | Distro: Fedora 37
2025-10-17 00:07:00.946272 | localhost | Provider: ansible-us-east-2
2025-10-17 00:07:00.946290 | localhost | Region: us-east-2
2025-10-17 00:07:00.946307 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-17 00:07:00.946323 | localhost | Product Name: t3.small
2025-10-17 00:07:00.946341 | localhost | Interface IP: 3.12.103.29
2025-10-17 00:07:00.960828 | 
2025-10-17 00:07:00.960936 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-17 00:07:01.325901 | localhost -> localhost | changed
2025-10-17 00:07:01.331506 | 
2025-10-17 00:07:01.331581 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-17 00:07:02.181645 | localhost -> localhost | changed
2025-10-17 00:07:02.209132 | 
2025-10-17 00:07:02.209200 | PLAY [all:!appliance*]
2025-10-17 00:07:02.226201 | 
2025-10-17 00:07:02.226285 | TASK [include_role : start-zuul-console]
2025-10-17 00:07:02.266530 | controller | ok
2025-10-17 00:07:02.279713 | 
2025-10-17 00:07:02.279781 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-17 00:07:03.291940 | controller | ok
2025-10-17 00:07:03.308772 | 
2025-10-17 00:07:03.308914 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-17 00:07:05.389194 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-17 00:07:05.397197 | 
2025-10-17 00:07:05.397332 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-17 00:07:05.573023 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.588207 | 
2025-10-17 00:07:05.588418 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-17 00:07:05.616078 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.630529 | 
2025-10-17 00:07:05.630720 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-17 00:07:05.658106 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.666591 | 
2025-10-17 00:07:05.666716 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-17 00:07:05.683172 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.694028 | 
2025-10-17 00:07:05.694151 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-17 00:07:05.719682 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.726172 | 
2025-10-17 00:07:05.726259 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-17 00:07:05.740292 | controller | skipping: Conditional result was False
2025-10-17 00:07:05.759511 | 
2025-10-17 00:07:05.759618 | TASK [Disable Fedora Modular]
2025-10-17 00:07:06.410908 | controller | changed
2025-10-17 00:07:06.429146 | 
2025-10-17 00:07:06.429359 | TASK [Enable EPEL]
2025-10-17 00:07:06.456486 | controller | skipping: Conditional result was False
2025-10-17 00:07:06.475821 | 
2025-10-17 00:07:06.475946 | TASK [Register the RHEL node]
2025-10-17 00:07:06.644517 | 
2025-10-17 00:07:06.644805 | TASK [Show the subscription-manager status]
2025-10-17 00:07:06.816273 | controller | skipping: Conditional result was False
2025-10-17 00:07:06.822608 | 
2025-10-17 00:07:06.822699 | TASK [Enable EPEL on RHEL]
2025-10-17 00:07:06.969751 | controller | skipping: Conditional result was False
2025-10-17 00:07:06.983579 | 
2025-10-17 00:07:06.983778 | TASK [Install git and tox]
2025-10-17 00:08:30.433028 | controller | changed
2025-10-17 00:08:30.442481 | 
2025-10-17 00:08:30.442580 | TASK [include_role : prepare-workspace]
2025-10-17 00:08:30.475036 | controller | ok
2025-10-17 00:08:30.511560 | 
2025-10-17 00:08:30.511796 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-17 00:08:31.045013 | controller | ok
2025-10-17 00:08:31.057377 | 
2025-10-17 00:08:31.057530 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-17 00:08:51.495445 | controller | Output suppressed because no_log was given
2025-10-17 00:08:51.509458 | 
2025-10-17 00:08:51.509536 | TASK [include_role : prepare-workspace-openshift]
2025-10-17 00:08:51.594891 | controller | skipping: Conditional result was False
2025-10-17 00:08:51.693883 | 
2025-10-17 00:08:51.693982 | PLAY [all:!appliance]
2025-10-17 00:08:51.713254 | 
2025-10-17 00:08:51.713368 | TASK [Run add-build-sshkey role (RSA)]
2025-10-17 00:08:51.756946 | controller | ok
2025-10-17 00:08:51.774295 | 
2025-10-17 00:08:51.774416 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-17 00:08:52.119244 | controller -> localhost | ok
2025-10-17 00:08:52.125807 | 
2025-10-17 00:08:52.125892 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-17 00:08:52.146617 | controller | ok
2025-10-17 00:08:52.166342 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-17 00:08:52.173225 | 
2025-10-17 00:08:52.173295 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-17 00:08:52.627443 | controller -> localhost | Generating public/private rsa key pair.
2025-10-17 00:08:52.627610 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_rsa.
2025-10-17 00:08:52.627639 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_rsa.pub.
2025-10-17 00:08:52.627660 | controller -> localhost | The key fingerprint is:
2025-10-17 00:08:52.627704 | controller -> localhost | SHA256:zTEO8gv47Gq+trcX57Oj5OrlMUerYyW8XR+l5KLkcZA zuul-build-sshkey
2025-10-17 00:08:52.627724 | controller -> localhost | The key's randomart image is:
2025-10-17 00:08:52.627743 | controller -> localhost | +---[RSA 2048]----+
2025-10-17 00:08:52.627762 | controller -> localhost | |                 |
2025-10-17 00:08:52.627781 | controller -> localhost | |                 |
2025-10-17 00:08:52.627799 | controller -> localhost | |      . . o.     |
2025-10-17 00:08:52.627819 | controller -> localhost | |     . o =Eo  . .|
2025-10-17 00:08:52.627839 | controller -> localhost | |    . ..S =. o o |
2025-10-17 00:08:52.627867 | controller -> localhost | |     o .+o=.+ +  |
2025-10-17 00:08:52.627890 | controller -> localhost | |      o *@o= o . |
2025-10-17 00:08:52.627909 | controller -> localhost | |    o..===B   .  |
2025-10-17 00:08:52.627927 | controller -> localhost | |   +=*===o.+     |
2025-10-17 00:08:52.627948 | controller -> localhost | +----[SHA256]-----+
2025-10-17 00:08:52.627990 | controller -> localhost | ok: Runtime: 0:00:00.033382
2025-10-17 00:08:52.634771 | 
2025-10-17 00:08:52.634881 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-17 00:08:52.666999 | controller | ok
2025-10-17 00:08:52.680064 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-17 00:08:52.692270 | 
2025-10-17 00:08:52.692392 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-17 00:08:52.718209 | controller | skipping: Conditional result was False
2025-10-17 00:08:52.726310 | 
2025-10-17 00:08:52.726379 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-17 00:08:53.385479 | controller | changed
2025-10-17 00:08:53.398661 | 
2025-10-17 00:08:53.398915 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-17 00:08:53.747056 | controller | ok
2025-10-17 00:08:53.766296 | 
2025-10-17 00:08:53.766462 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-17 00:08:55.341402 | controller | changed
2025-10-17 00:08:55.357655 | 
2025-10-17 00:08:55.357887 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-17 00:08:56.603931 | controller | changed
2025-10-17 00:08:56.619021 | 
2025-10-17 00:08:56.619181 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-17 00:08:56.647529 | controller | skipping: Conditional result was False
2025-10-17 00:08:56.661103 | 
2025-10-17 00:08:56.661266 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-17 00:08:57.096388 | controller -> localhost | changed
2025-10-17 00:08:57.142046 | 
2025-10-17 00:08:57.142282 | TASK [add-build-sshkey : Add back temp key]
2025-10-17 00:08:57.547900 | controller -> localhost | Identity added: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_rsa (zuul-build-sshkey)
2025-10-17 00:08:57.548200 | controller -> localhost | ok: Runtime: 0:00:00.009823
2025-10-17 00:08:57.555852 | 
2025-10-17 00:08:57.556056 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-17 00:08:58.114431 | controller | ok
2025-10-17 00:08:58.125826 | 
2025-10-17 00:08:58.126051 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-17 00:08:58.180146 | controller | skipping: Conditional result was False
2025-10-17 00:08:58.198011 | 
2025-10-17 00:08:58.198167 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-17 00:08:58.219202 | controller | ok
2025-10-17 00:08:58.237912 | 
2025-10-17 00:08:58.237987 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-17 00:08:58.509422 | controller -> localhost | ok
2025-10-17 00:08:58.537190 | 
2025-10-17 00:08:58.537321 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-17 00:08:58.569223 | controller | ok
2025-10-17 00:08:58.581377 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-17 00:08:58.587693 | 
2025-10-17 00:08:58.587759 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-17 00:08:58.879889 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-17 00:08:58.880100 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_ecdsa.
2025-10-17 00:08:58.880133 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_ecdsa.pub.
2025-10-17 00:08:58.880164 | controller -> localhost | The key fingerprint is:
2025-10-17 00:08:58.880185 | controller -> localhost | SHA256:M3t9Wyq85mizOt7amEKF8DbKSXKns7ikPo3ZY7JKxoI zuul-build-sshkey
2025-10-17 00:08:58.880207 | controller -> localhost | The key's randomart image is:
2025-10-17 00:08:58.880227 | controller -> localhost | +---[ECDSA 521]---+
2025-10-17 00:08:58.880246 | controller -> localhost | |                 |
2025-10-17 00:08:58.880264 | controller -> localhost | |    .            |
2025-10-17 00:08:58.880281 | controller -> localhost | |     o .         |
2025-10-17 00:08:58.880299 | controller -> localhost | |  . o * .        |
2025-10-17 00:08:58.880317 | controller -> localhost | |   = * oS        |
2025-10-17 00:08:58.880334 | controller -> localhost | |o   * .  + .     |
2025-10-17 00:08:58.880351 | controller -> localhost | |E+*. +  . ... . .|
2025-10-17 00:08:58.880368 | controller -> localhost | |+B.=. . .*o.+. + |
2025-10-17 00:08:58.880385 | controller -> localhost | |=o*..  o*===ooo  |
2025-10-17 00:08:58.880403 | controller -> localhost | +----[SHA256]-----+
2025-10-17 00:08:58.880450 | controller -> localhost | ok: Runtime: 0:00:00.011501
2025-10-17 00:08:58.890455 | 
2025-10-17 00:08:58.890557 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-17 00:08:58.920192 | controller | ok
2025-10-17 00:08:58.928033 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-17 00:08:58.937224 | 
2025-10-17 00:08:58.937304 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-17 00:08:58.961537 | controller | skipping: Conditional result was False
2025-10-17 00:08:58.968555 | 
2025-10-17 00:08:58.968622 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-17 00:08:59.418509 | controller | changed
2025-10-17 00:08:59.427600 | 
2025-10-17 00:08:59.427777 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-17 00:08:59.761465 | controller | ok
2025-10-17 00:08:59.767566 | 
2025-10-17 00:08:59.767629 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-17 00:09:01.277899 | controller | changed
2025-10-17 00:09:01.292792 | 
2025-10-17 00:09:01.293017 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-17 00:09:03.363738 | controller | changed
2025-10-17 00:09:03.373403 | 
2025-10-17 00:09:03.373503 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-17 00:09:03.410976 | controller | skipping: Conditional result was False
2025-10-17 00:09:03.421446 | 
2025-10-17 00:09:03.421571 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-17 00:09:03.749160 | controller -> localhost | changed
2025-10-17 00:09:03.816638 | 
2025-10-17 00:09:03.816784 | TASK [add-build-sshkey : Add back temp key]
2025-10-17 00:09:04.200776 | controller -> localhost | Identity added: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/b7bfed213b19489b8a30c32b88daeb2c_id_ecdsa (zuul-build-sshkey)
2025-10-17 00:09:04.201273 | controller -> localhost | ok: Runtime: 0:00:00.025438
2025-10-17 00:09:04.218321 | 
2025-10-17 00:09:04.218511 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-17 00:09:04.604154 | controller | ok
2025-10-17 00:09:04.614393 | 
2025-10-17 00:09:04.615339 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-17 00:09:04.663424 | controller | skipping: Conditional result was False
2025-10-17 00:09:04.708952 | 
2025-10-17 00:09:04.709085 | TASK [include_role : remove-zuul-sshkey]
2025-10-17 00:09:04.750255 | controller | skipping: Conditional result was False
2025-10-17 00:09:04.758778 | 
2025-10-17 00:09:04.758945 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-17 00:09:05.106619 | controller | ok: "logs"
2025-10-17 00:09:05.107017 | controller | ok: All items complete
2025-10-17 00:09:05.107056 | 
2025-10-17 00:09:05.431473 | controller | ok: "artifacts"
2025-10-17 00:09:05.739862 | controller | ok: "docs"
2025-10-17 00:09:05.747574 | 
2025-10-17 00:09:05.747646 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-17 00:09:06.206083 | controller | changed: "logs"
2025-10-17 00:09:06.755223 | controller | changed: "artifacts"
2025-10-17 00:09:07.069024 | controller | changed: "docs"
2025-10-17 00:09:07.118534 | 
2025-10-17 00:09:07.118712 | PLAY RECAP
2025-10-17 00:09:07.118765 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-17 00:09:07.118792 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-17 00:09:07.118811 | 
2025-10-17 00:09:07.412223 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-17 00:09:07.413159 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-17 00:09:08.084996 | 
2025-10-17 00:09:08.085117 | PLAY [all]
2025-10-17 00:09:08.108266 | 
2025-10-17 00:09:08.108370 | TASK [Install binary dependencies]
2025-10-17 00:09:08.158484 | controller | ok
2025-10-17 00:09:08.179788 | 
2025-10-17 00:09:08.179874 | TASK [bindep : Include find tasks]
2025-10-17 00:09:08.208876 | controller | ok
2025-10-17 00:09:08.218649 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-17 00:09:08.225323 | 
2025-10-17 00:09:08.225390 | TASK [bindep : Look for bindep.txt]
2025-10-17 00:09:08.861071 | controller | ok
2025-10-17 00:09:08.867487 | 
2025-10-17 00:09:08.867564 | TASK [bindep : Define bindep_file fact]
2025-10-17 00:09:08.890731 | controller | skipping: Conditional result was False
2025-10-17 00:09:08.897147 | 
2025-10-17 00:09:08.897224 | TASK [bindep : Look for other-requirements.txt]
2025-10-17 00:09:09.203219 | controller | ok
2025-10-17 00:09:09.208591 | 
2025-10-17 00:09:09.208679 | TASK [bindep : Define bindep_file fact]
2025-10-17 00:09:09.239028 | controller | skipping: Conditional result was False
2025-10-17 00:09:09.246492 | 
2025-10-17 00:09:09.246588 | TASK [bindep : Look for bindep fallback file]
2025-10-17 00:09:09.270708 | controller | skipping: Conditional result was False
2025-10-17 00:09:09.282068 | 
2025-10-17 00:09:09.282225 | TASK [bindep : Define bindep_file fact]
2025-10-17 00:09:09.307227 | controller | skipping: Conditional result was False
2025-10-17 00:09:09.319676 | 
2025-10-17 00:09:09.320443 | TASK [bindep : Include bindep tasks]
2025-10-17 00:09:09.381623 | controller | skipping: Conditional result was False
2025-10-17 00:09:09.389104 | 
2025-10-17 00:09:09.389207 | TASK [bindep : Include install tasks]
2025-10-17 00:09:09.423872 | controller | skipping: Conditional result was False
2025-10-17 00:09:09.430470 | 
2025-10-17 00:09:09.430610 | LOOP [bindep : Include package tasks]
2025-10-17 00:09:09.487286 | 
2025-10-17 00:09:09.487447 | TASK [Run test-setup role]
2025-10-17 00:09:09.507363 | controller | ok
2025-10-17 00:09:09.530649 | 
2025-10-17 00:09:09.530795 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-17 00:09:09.846224 | controller | ok
2025-10-17 00:09:09.852351 | 
2025-10-17 00:09:09.852428 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-17 00:09:09.989259 | controller | skipping: Conditional result was False
2025-10-17 00:09:10.016779 | 
2025-10-17 00:09:10.016898 | PLAY RECAP
2025-10-17 00:09:10.016941 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-17 00:09:10.016962 | 
2025-10-17 00:09:10.188945 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-17 00:09:10.189949 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-17 00:09:10.772555 | 
2025-10-17 00:09:10.772700 | PLAY [controller]
2025-10-17 00:09:10.791900 | 
2025-10-17 00:09:10.791974 | TASK [Create the /root directory]
2025-10-17 00:09:11.524645 | controller | ok
2025-10-17 00:09:11.538265 | 
2025-10-17 00:09:11.538465 | TASK [Install glibc-langpack-en]
2025-10-17 00:09:19.743695 | controller | ok: Nothing to do
2025-10-17 00:09:19.756646 | 
2025-10-17 00:09:19.756867 | TASK [Ensure controller directory exists]
2025-10-17 00:09:20.561961 | controller | changed
2025-10-17 00:09:20.567601 | 
2025-10-17 00:09:20.567694 | TASK [Install container runtime]
2025-10-17 00:09:20.663309 | controller | ok
2025-10-17 00:09:20.709202 | 
2025-10-17 00:09:20.709365 | LOOP [ensure-podman : Find distribution installation]
2025-10-17 00:09:20.738129 | controller | ok: "/var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-17 00:09:20.757126 | controller | included: /var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-17 00:09:20.765014 | 
2025-10-17 00:09:20.765090 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-17 00:10:36.523762 | controller | changed
2025-10-17 00:10:36.547238 | 
2025-10-17 00:10:36.550746 | TASK [ensure-podman : Fetch podman version]
2025-10-17 00:10:37.233566 | controller | Client:       Podman Engine
2025-10-17 00:10:37.260912 | controller | Version:      4.6.2
2025-10-17 00:10:37.260953 | controller | API Version:  4.6.2
2025-10-17 00:10:37.260961 | controller | Go Version:   go1.19.12
2025-10-17 00:10:37.260979 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-17 00:10:37.260987 | controller | OS/Arch:      linux/amd64
2025-10-17 00:10:37.700847 | controller | ok: Runtime: 0:00:00.218164
2025-10-17 00:10:37.710195 | 
2025-10-17 00:10:37.710369 | TASK [ensure-podman : Print podman version installed]
2025-10-17 00:10:37.740980 | Podman version: Client:       Podman Engine
2025-10-17 00:10:37.741122 | Version:      4.6.2
2025-10-17 00:10:37.741151 | API Version:  4.6.2
2025-10-17 00:10:37.741172 | Go Version:   go1.19.12
2025-10-17 00:10:37.741191 | Built:        Mon Aug 28 19:38:31 2023
2025-10-17 00:10:37.741210 | OS/Arch:      linux/amd64
2025-10-17 00:10:37.747874 | 
2025-10-17 00:10:37.747937 | TASK [ensure-podman : Validate podman engine]
2025-10-17 00:10:37.886383 | controller | skipping: Conditional result was False
2025-10-17 00:10:37.893086 | 
2025-10-17 00:10:37.893158 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-17 00:10:37.916817 | controller | skipping: Conditional result was False
2025-10-17 00:10:37.933605 | 
2025-10-17 00:10:37.933733 | TASK [Ensure python3.8 is present]
2025-10-17 00:10:37.957984 | controller | skipping: Conditional result was False
2025-10-17 00:10:37.964715 | 
2025-10-17 00:10:37.964810 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-17 00:10:37.984536 | controller | ok
2025-10-17 00:10:38.018650 | 
2025-10-17 00:10:38.018807 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-17 00:10:41.758074 | controller | ok: Nothing to do
2025-10-17 00:10:41.764449 | 
2025-10-17 00:10:41.764552 | TASK [our-ensure-python : Also install python3-devel]
2025-10-17 00:10:54.903406 | controller | changed
2025-10-17 00:10:54.921891 | 
2025-10-17 00:10:54.922092 | TASK [Run ensure-virtualenv role]
2025-10-17 00:10:54.952978 | controller | ok
2025-10-17 00:10:54.976218 | 
2025-10-17 00:10:54.976331 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-17 00:10:55.361576 | controller | /usr/bin/virtualenv
2025-10-17 00:10:55.612177 | controller | ok: Runtime: 0:00:00.004416
2025-10-17 00:10:55.622352 | 
2025-10-17 00:10:55.622441 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-17 00:10:55.654958 | controller | skipping: Conditional result was False
2025-10-17 00:10:55.657829 | controller | ok: All items complete
2025-10-17 00:10:55.657867 | 
2025-10-17 00:10:55.682536 | 
2025-10-17 00:10:55.682780 | TASK [Find the full path of the Python interpreter]
2025-10-17 00:10:56.208787 | controller | /usr/bin/python3
2025-10-17 00:10:56.434188 | controller | ok
2025-10-17 00:10:56.442789 | 
2025-10-17 00:10:56.442890 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-17 00:10:57.897492 | controller | created virtual environment CPython3.11.0.final.0-64 in 746ms
2025-10-17 00:10:57.937258 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-17 00:10:57.937311 | 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-17 00:10:57.937328 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-17 00:10:57.937351 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-17 00:10:58.108896 | controller | changed
2025-10-17 00:10:58.115287 | 
2025-10-17 00:10:58.115366 | TASK [Set selinux package]
2025-10-17 00:10:58.146545 | controller | ok
2025-10-17 00:10:58.154432 | 
2025-10-17 00:10:58.154550 | TASK [Set selinux package (Fedora)]
2025-10-17 00:10:58.199960 | controller | ok
2025-10-17 00:10:58.205894 | 
2025-10-17 00:10:58.206008 | TASK [Install selinux into virtualenv]
2025-10-17 00:11:00.884320 | controller | Collecting selinux-please-lie-to-me
2025-10-17 00:11:00.982759 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-17 00:11:01.516074 | controller | Collecting setuptools<50.0.0
2025-10-17 00:11:01.532358 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-17 00:11:01.631016 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 8.6 MB/s eta 0:00:00
2025-10-17 00:11:01.790874 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-17 00:11:01.791308 | controller |   Attempting uninstall: setuptools
2025-10-17 00:11:01.796420 | controller |     Found existing installation: setuptools 62.6.0
2025-10-17 00:11:01.915846 | controller |     Uninstalling setuptools-62.6.0:
2025-10-17 00:11:01.932119 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-17 00:11:02.729613 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-17 00:11:02.940895 | controller |
2025-10-17 00:11:03.164214 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-17 00:11:03.164277 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-17 00:11:03.379156 | controller | ok: Runtime: 0:00:04.461748
2025-10-17 00:11:03.384985 | 
2025-10-17 00:11:03.385055 | TASK [Install pytest-forked into virtualenv]
2025-10-17 00:11:04.571719 | controller | Collecting pytest-forked
2025-10-17 00:11:04.669510 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-17 00:11:04.729571 | controller | Collecting py
2025-10-17 00:11:04.761246 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-17 00:11:04.797222 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00
2025-10-17 00:11:04.971330 | controller | Collecting pytest>=3.10
2025-10-17 00:11:04.988385 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-17 00:11:05.054536 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 5.7 MB/s eta 0:00:00
2025-10-17 00:11:05.110014 | controller | Collecting iniconfig>=1
2025-10-17 00:11:05.143352 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-17 00:11:05.210977 | controller | Collecting packaging>=20
2025-10-17 00:11:05.232242 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-17 00:11:05.269247 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 1.7 MB/s eta 0:00:00
2025-10-17 00:11:05.312526 | controller | Collecting pluggy<2,>=1.5
2025-10-17 00:11:05.342573 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-17 00:11:05.434044 | controller | Collecting pygments>=2.7.2
2025-10-17 00:11:05.464460 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-17 00:11:05.584732 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 10.4 MB/s eta 0:00:00
2025-10-17 00:11:05.717866 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-17 00:11:07.939333 | 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-17 00:11:07.957835 | controller |
2025-10-17 00:11:08.139013 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-17 00:11:08.139056 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-17 00:11:08.558334 | controller | ok: Runtime: 0:00:04.300949
2025-10-17 00:11:08.566899 | 
2025-10-17 00:11:08.567041 | TASK [Update pip]
2025-10-17 00:11:09.683883 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-17 00:11:09.963684 | controller | Collecting pip
2025-10-17 00:11:10.062906 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-17 00:11:10.226557 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 11.0 MB/s eta 0:00:00
2025-10-17 00:11:10.394600 | controller | Installing collected packages: pip
2025-10-17 00:11:10.394903 | controller |   Attempting uninstall: pip
2025-10-17 00:11:10.402680 | controller |     Found existing installation: pip 22.2.2
2025-10-17 00:11:10.732809 | controller |     Uninstalling pip-22.2.2:
2025-10-17 00:11:10.779954 | controller |       Successfully uninstalled pip-22.2.2
2025-10-17 00:11:12.552287 | controller | Successfully installed pip-25.2
2025-10-17 00:11:13.211514 | controller | ok: Runtime: 0:00:03.664649
2025-10-17 00:11:13.217185 | 
2025-10-17 00:11:13.217256 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-17 00:11:13.765126 | controller | changed
2025-10-17 00:11:13.770430 | 
2025-10-17 00:11:13.770493 | TASK [Install ansible into virtualenv]
2025-10-17 00:11:14.817113 | controller | Processing ./src/github.com/ansible/ansible
2025-10-17 00:11:14.823321 | controller |   Installing build dependencies: started
2025-10-17 00:11:16.750391 | controller |   Installing build dependencies: finished with status 'done'
2025-10-17 00:11:18.254293 | controller |   Getting requirements to build wheel: started
2025-10-17 00:11:18.254367 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-17 00:11:18.255944 | controller |   Preparing metadata (pyproject.toml): started
2025-10-17 00:11:19.175298 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-17 00:11:19.180196 | 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-17 00:11:19.185145 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-17 00:11:19.406802 | controller | ERROR
2025-10-17 00:11:19.407016 | controller | {
2025-10-17 00:11:19.407062 | controller |   "delta": "0:00:05.164121",
2025-10-17 00:11:19.407099 | controller |   "end": "2025-10-17 00:11:19.331401",
2025-10-17 00:11:19.407133 | controller |   "msg": "non-zero return code",
2025-10-17 00:11:19.407176 | controller |   "rc": 1,
2025-10-17 00:11:19.407206 | controller |   "start": "2025-10-17 00:11:14.167280"
2025-10-17 00:11:19.407235 | controller | }
failure
2025-10-17 00:11:19.421416 | 
2025-10-17 00:11:19.421541 | PLAY RECAP
2025-10-17 00:11:19.421592 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-17 00:11:19.421614 | 
2025-10-17 00:11:19.617701 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-17 00:11:19.618861 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-17 00:11:20.509504 | 
2025-10-17 00:11:20.509634 | PLAY [all]
2025-10-17 00:11:20.533480 | 
2025-10-17 00:11:20.533612 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-17 00:11:21.304041 | controller | changed: non-zero return code
2025-10-17 00:11:21.314380 | 
2025-10-17 00:11:21.314525 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-17 00:11:21.340353 | controller | skipping: Conditional result was False
2025-10-17 00:11:21.348489 | 
2025-10-17 00:11:21.348613 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-17 00:11:21.383380 | 
2025-10-17 00:11:21.383537 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-17 00:11:21.414158 | 
2025-10-17 00:11:21.414321 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-17 00:11:21.439561 | controller | skipping: Conditional result was False
2025-10-17 00:11:21.448513 | 
2025-10-17 00:11:21.448606 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-17 00:11:21.475226 | 
2025-10-17 00:11:21.475404 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-17 00:11:21.499065 | controller | skipping: Conditional result was False
2025-10-17 00:11:21.507897 | 
2025-10-17 00:11:21.508074 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-17 00:11:21.549875 | controller | skipping: Conditional result was False
2025-10-17 00:11:21.560153 | 
2025-10-17 00:11:21.560305 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-17 00:11:21.600036 | controller | skipping: Conditional result was False
2025-10-17 00:11:21.680560 | 
2025-10-17 00:11:21.680728 | PLAY RECAP
2025-10-17 00:11:21.680791 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-17 00:11:21.680821 | 
2025-10-17 00:11:21.968221 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-17 00:11:21.969269 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-17 00:11:24.793588 | 
2025-10-17 00:11:24.793761 | PLAY [all:!appliance*]
2025-10-17 00:11:24.816579 | 
2025-10-17 00:11:24.816741 | TASK [unregister the node]
2025-10-17 00:11:24.949202 | controller | skipping: Conditional result was False
2025-10-17 00:11:24.956685 | 
2025-10-17 00:11:24.956838 | TASK [include_role : fetch-output]
2025-10-17 00:11:24.996904 | controller | ok
2025-10-17 00:11:25.017621 | 
2025-10-17 00:11:25.017786 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-17 00:11:25.105468 | controller | skipping: Conditional result was False
2025-10-17 00:11:25.118713 | 
2025-10-17 00:11:25.118831 | TASK [fetch-output : Set log path for single node]
2025-10-17 00:11:25.166374 | controller | ok
2025-10-17 00:11:25.179752 | 
2025-10-17 00:11:25.179887 | LOOP [fetch-output : Ensure local output dirs]
2025-10-17 00:11:25.632546 | controller -> localhost | ok: "/var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/logs"
2025-10-17 00:11:25.875927 | controller -> localhost | changed: "/var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/artifacts"
2025-10-17 00:11:26.142785 | controller -> localhost | changed: "/var/lib/zuul/builds/b7bfed213b19489b8a30c32b88daeb2c/work/docs"
2025-10-17 00:11:26.154794 | 
2025-10-17 00:11:26.154915 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-17 00:11:27.385848 | controller | changed:
2025-10-17 00:11:27.386182 | controller | .d..t...... ./
2025-10-17 00:11:27.386234 | controller | cd+++++++++ controller/
2025-10-17 00:11:27.386273 | controller | changed: All items complete
2025-10-17 00:11:27.386295 | 
2025-10-17 00:11:28.486227 | controller | changed: .d..t...... ./
2025-10-17 00:11:29.594320 | controller | changed: .d..t...... ./
2025-10-17 00:11:29.606686 | 
2025-10-17 00:11:29.606845 | TASK [include_role : fetch-output-openshift]
2025-10-17 00:11:29.633262 | controller | skipping: Conditional result was False
2025-10-17 00:11:29.640250 | 
2025-10-17 00:11:29.640329 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-17 00:11:29.669385 | controller | skipping: Conditional result was False
2025-10-17 00:11:29.682295 | controller | skipping: Conditional result was False
2025-10-17 00:11:29.714304 | 
2025-10-17 00:11:29.714384 | PLAY [localhost]
2025-10-17 00:11:29.727446 | 
2025-10-17 00:11:29.727521 | TASK [Run Zuul manifest role]
2025-10-17 00:11:29.748364 | localhost | ok
2025-10-17 00:11:29.766386 | 
2025-10-17 00:11:29.766562 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-17 00:11:30.180529 | localhost | changed
2025-10-17 00:11:30.187045 | 
2025-10-17 00:11:30.187142 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-17 00:11:30.217044 | localhost | ok
2025-10-17 00:11:30.225092 | 
2025-10-17 00:11:30.225153 | TASK [Set zuul-log-path fact]
2025-10-17 00:11:30.243226 | localhost | ok
2025-10-17 00:11:30.258209 | 
2025-10-17 00:11:30.258289 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-17 00:11:30.286430 | localhost | ok
2025-10-17 00:11:30.295564 | 
2025-10-17 00:11:30.295631 | LOOP [Run upload-logs-swift role]
2025-10-17 00:11:30.339862 | localhost | Output suppressed because no_log was given
2025-10-17 00:11:30.366354 | 
2025-10-17 00:11:30.366456 | TASK [Set zuul-log-path fact]
2025-10-17 00:11:30.391209 | localhost | skipping: Conditional result was False
2025-10-17 00:11:30.397066 | 
2025-10-17 00:11:30.397141 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-17 00:11:30.840251 | localhost -> localhost | ok: Runtime: 0:00:00.011262
2025-10-17 00:11:30.845913 | 
2025-10-17 00:11:30.845974 | TASK [upload-logs-swift : Upload logs to swift]