2025-11-07 00:13:17.449353 | Job console starting...
2025-11-07 00:13:17.460227 | Updating repositories
2025-11-07 00:13:17.626236 | Preparing job workspace
2025-11-07 00:13:21.143868 | Running Ansible setup...
2025-11-07 00:13:25.836186 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-07 00:13:26.513330 | 
2025-11-07 00:13:26.513466 | PLAY [localhost]
2025-11-07 00:13:26.521904 | 
2025-11-07 00:13:26.522269 | TASK [Gathering Facts]
2025-11-07 00:13:27.482765 | localhost | ok
2025-11-07 00:13:27.505232 | 
2025-11-07 00:13:27.505370 | TASK [Setup log path fact]
2025-11-07 00:13:27.523375 | localhost | ok
2025-11-07 00:13:27.537222 | 
2025-11-07 00:13:27.537347 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-07 00:13:27.565265 | localhost | ok
2025-11-07 00:13:27.573794 | 
2025-11-07 00:13:27.573901 | TASK [emit-job-header : Print job information]
2025-11-07 00:13:27.616426 | # Job Information
2025-11-07 00:13:27.616579 | Ansible Version: 2.15.12
2025-11-07 00:13:27.616612 | Job: ansible-test-sanity-docker-devel
2025-11-07 00:13:27.616635 | Pipeline: periodic
2025-11-07 00:13:27.616655 | Executor: ze01.softwarefactory-project.io
2025-11-07 00:13:27.616674 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-07 00:13:27.616697 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b78/ansible/b78007046b324289be6694b3cf93bcdd/
2025-11-07 00:13:27.616717 | Event ID: 75db9354acf84300bc89d0c9903cd922
2025-11-07 00:13:27.622470 | 
2025-11-07 00:13:27.622555 | LOOP [emit-job-header : Print node information]
2025-11-07 00:13:27.730983 | localhost | ok:
2025-11-07 00:13:27.733179 | localhost | # Node Information
2025-11-07 00:13:27.733209 | localhost | Inventory Hostname: controller
2025-11-07 00:13:27.733229 | localhost | Hostname: np0005514188
2025-11-07 00:13:27.733250 | localhost | Username: zuul
2025-11-07 00:13:27.733272 | localhost | Distro: Fedora 37
2025-11-07 00:13:27.733291 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-11-07 00:13:27.733309 | localhost | Region: ca-ymq-1
2025-11-07 00:13:27.733327 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-07 00:13:27.733344 | localhost | Product Name: OpenStack Nova
2025-11-07 00:13:27.733362 | localhost | Interface IP: 162.253.55.52
2025-11-07 00:13:27.750897 | 
2025-11-07 00:13:27.751037 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-07 00:13:28.225320 | localhost -> localhost | changed
2025-11-07 00:13:28.231371 | 
2025-11-07 00:13:28.231537 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-07 00:13:29.161938 | localhost -> localhost | changed
2025-11-07 00:13:29.188775 | 
2025-11-07 00:13:29.188955 | PLAY [all:!appliance*]
2025-11-07 00:13:29.207765 | 
2025-11-07 00:13:29.207886 | TASK [include_role : start-zuul-console]
2025-11-07 00:13:29.228403 | controller | ok
2025-11-07 00:13:29.243132 | 
2025-11-07 00:13:29.243240 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-07 00:13:29.671970 | controller | ok
2025-11-07 00:13:29.696363 | 
2025-11-07 00:13:29.696497 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-07 00:13:52.488848 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-07 00:13:52.503663 | 
2025-11-07 00:13:52.503799 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-07 00:13:53.052718 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.067193 | 
2025-11-07 00:13:53.067342 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-07 00:13:53.104536 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.118165 | 
2025-11-07 00:13:53.118310 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-07 00:13:53.156548 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.169860 | 
2025-11-07 00:13:53.170006 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-07 00:13:53.206801 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.220785 | 
2025-11-07 00:13:53.221291 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-07 00:13:53.248232 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.262392 | 
2025-11-07 00:13:53.262563 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-07 00:13:53.289594 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.308300 | 
2025-11-07 00:13:53.308465 | TASK [Disable Fedora Modular]
2025-11-07 00:13:53.653558 | controller | changed
2025-11-07 00:13:53.667233 | 
2025-11-07 00:13:53.667413 | TASK [Enable EPEL]
2025-11-07 00:13:53.694757 | controller | skipping: Conditional result was False
2025-11-07 00:13:53.705161 | 
2025-11-07 00:13:53.705322 | TASK [Register the RHEL node]
2025-11-07 00:13:54.271830 | 
2025-11-07 00:13:54.272056 | TASK [Show the subscription-manager status]
2025-11-07 00:13:54.828291 | controller | skipping: Conditional result was False
2025-11-07 00:13:54.842773 | 
2025-11-07 00:13:54.842952 | TASK [Enable EPEL on RHEL]
2025-11-07 00:13:55.405460 | controller | skipping: Conditional result was False
2025-11-07 00:13:55.419743 | 
2025-11-07 00:13:55.419923 | TASK [Install git and tox]
2025-11-07 00:15:31.422846 | controller | changed
2025-11-07 00:15:31.437968 | 
2025-11-07 00:15:31.438200 | TASK [include_role : prepare-workspace]
2025-11-07 00:15:31.480402 | controller | ok
2025-11-07 00:15:31.517505 | 
2025-11-07 00:15:31.517653 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-07 00:15:31.750127 | controller | ok
2025-11-07 00:15:31.764885 | 
2025-11-07 00:15:31.765077 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-07 00:15:46.116765 | controller | Output suppressed because no_log was given
2025-11-07 00:15:46.131776 | 
2025-11-07 00:15:46.131862 | TASK [include_role : prepare-workspace-openshift]
2025-11-07 00:15:46.148032 | controller | skipping: Conditional result was False
2025-11-07 00:15:46.206684 | 
2025-11-07 00:15:46.206760 | PLAY [all:!appliance]
2025-11-07 00:15:46.222830 | 
2025-11-07 00:15:46.222922 | TASK [Run add-build-sshkey role (RSA)]
2025-11-07 00:15:46.243364 | controller | ok
2025-11-07 00:15:46.259032 | 
2025-11-07 00:15:46.259123 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-07 00:15:46.487066 | controller -> localhost | ok
2025-11-07 00:15:46.494945 | 
2025-11-07 00:15:46.495082 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-07 00:15:46.527413 | controller | ok
2025-11-07 00:15:46.542198 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-07 00:15:46.549484 | 
2025-11-07 00:15:46.549609 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-07 00:15:47.040153 | controller -> localhost | Generating public/private rsa key pair.
2025-11-07 00:15:47.040371 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_rsa.
2025-11-07 00:15:47.040409 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_rsa.pub.
2025-11-07 00:15:47.040433 | controller -> localhost | The key fingerprint is:
2025-11-07 00:15:47.040453 | controller -> localhost | SHA256:Bwc4BlliiobSoynQts86x1jmaUOp8SsxoSH9S12RVlY zuul-build-sshkey
2025-11-07 00:15:47.040475 | controller -> localhost | The key's randomart image is:
2025-11-07 00:15:47.040495 | controller -> localhost | +---[RSA 2048]----+
2025-11-07 00:15:47.040516 | controller -> localhost | |    ++...oo.E    |
2025-11-07 00:15:47.040537 | controller -> localhost | |.+ o..+ +o       |
2025-11-07 00:15:47.040558 | controller -> localhost | |=o*  . o...      |
2025-11-07 00:15:47.040578 | controller -> localhost | |*+oo    .o       |
2025-11-07 00:15:47.040598 | controller -> localhost | |=o.o o .S .      |
2025-11-07 00:15:47.040629 | controller -> localhost | |o +oB .  .       |
2025-11-07 00:15:47.040654 | controller -> localhost | |   #oo           |
2025-11-07 00:15:47.040678 | controller -> localhost | |  =.X            |
2025-11-07 00:15:47.040698 | controller -> localhost | |  .=.o           |
2025-11-07 00:15:47.040721 | controller -> localhost | +----[SHA256]-----+
2025-11-07 00:15:47.040770 | controller -> localhost | ok: Runtime: 0:00:00.087940
2025-11-07 00:15:47.048239 | 
2025-11-07 00:15:47.048322 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-07 00:15:47.078437 | controller | ok
2025-11-07 00:15:47.090112 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-07 00:15:47.099424 | 
2025-11-07 00:15:47.099491 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-07 00:15:47.123546 | controller | skipping: Conditional result was False
2025-11-07 00:15:47.130606 | 
2025-11-07 00:15:47.130680 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-07 00:15:47.605432 | controller | changed
2025-11-07 00:15:47.612189 | 
2025-11-07 00:15:47.612270 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-07 00:15:47.837305 | controller | ok
2025-11-07 00:15:47.844093 | 
2025-11-07 00:15:47.844173 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-07 00:15:48.514195 | controller | changed
2025-11-07 00:15:48.523692 | 
2025-11-07 00:15:48.523837 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-07 00:15:49.178392 | controller | changed
2025-11-07 00:15:49.206937 | 
2025-11-07 00:15:49.207116 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-07 00:15:49.239714 | controller | skipping: Conditional result was False
2025-11-07 00:15:49.255282 | 
2025-11-07 00:15:49.255452 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-07 00:15:49.661718 | controller -> localhost | changed
2025-11-07 00:15:49.691918 | 
2025-11-07 00:15:49.692145 | TASK [add-build-sshkey : Add back temp key]
2025-11-07 00:15:50.087037 | controller -> localhost | Identity added: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_rsa (zuul-build-sshkey)
2025-11-07 00:15:50.087308 | controller -> localhost | ok: Runtime: 0:00:00.021082
2025-11-07 00:15:50.103783 | 
2025-11-07 00:15:50.103936 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-07 00:15:50.525215 | controller | ok
2025-11-07 00:15:50.540670 | 
2025-11-07 00:15:50.540836 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-07 00:15:50.564982 | controller | skipping: Conditional result was False
2025-11-07 00:15:50.576947 | 
2025-11-07 00:15:50.577089 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-07 00:15:50.599583 | controller | ok
2025-11-07 00:15:50.617472 | 
2025-11-07 00:15:50.617602 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-07 00:15:50.860604 | controller -> localhost | ok
2025-11-07 00:15:50.867882 | 
2025-11-07 00:15:50.868009 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-07 00:15:50.898410 | controller | ok
2025-11-07 00:15:50.909574 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-07 00:15:50.918076 | 
2025-11-07 00:15:50.918212 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-07 00:15:51.208462 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-07 00:15:51.208712 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_ecdsa.
2025-11-07 00:15:51.208751 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_ecdsa.pub.
2025-11-07 00:15:51.208786 | controller -> localhost | The key fingerprint is:
2025-11-07 00:15:51.208811 | controller -> localhost | SHA256:84IB1QDhx2LkQ5k/b6qGP4o3eOTRamPsLt+u/R3YEzA zuul-build-sshkey
2025-11-07 00:15:51.208835 | controller -> localhost | The key's randomart image is:
2025-11-07 00:15:51.208858 | controller -> localhost | +---[ECDSA 521]---+
2025-11-07 00:15:51.208880 | controller -> localhost | |    ==oo         |
2025-11-07 00:15:51.208902 | controller -> localhost | |   =oo  .        |
2025-11-07 00:15:51.208923 | controller -> localhost | |    B.E          |
2025-11-07 00:15:51.208944 | controller -> localhost | |   . =oo         |
2025-11-07 00:15:51.208966 | controller -> localhost | |   .  .oS        |
2025-11-07 00:15:51.208986 | controller -> localhost | |  o .  =o+       |
2025-11-07 00:15:51.209007 | controller -> localhost | | = +  oo= .      |
2025-11-07 00:15:51.209228 | controller -> localhost | |o.%oo .. +       |
2025-11-07 00:15:51.209260 | controller -> localhost | |.X*O*+. .        |
2025-11-07 00:15:51.209283 | controller -> localhost | +----[SHA256]-----+
2025-11-07 00:15:51.209343 | controller -> localhost | ok: Runtime: 0:00:00.010145
2025-11-07 00:15:51.219731 | 
2025-11-07 00:15:51.219848 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-07 00:15:51.245690 | controller | ok
2025-11-07 00:15:51.256794 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-07 00:15:51.270792 | 
2025-11-07 00:15:51.270948 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-07 00:15:51.297477 | controller | skipping: Conditional result was False
2025-11-07 00:15:51.306218 | 
2025-11-07 00:15:51.306303 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-07 00:15:51.573949 | controller | changed
2025-11-07 00:15:51.584119 | 
2025-11-07 00:15:51.584274 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-07 00:15:51.815924 | controller | ok
2025-11-07 00:15:51.826049 | 
2025-11-07 00:15:51.826189 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-07 00:15:52.428255 | controller | changed
2025-11-07 00:15:52.435741 | 
2025-11-07 00:15:52.435845 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-07 00:15:53.061475 | controller | changed
2025-11-07 00:15:53.081679 | 
2025-11-07 00:15:53.081832 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-07 00:15:53.105951 | controller | skipping: Conditional result was False
2025-11-07 00:15:53.115917 | 
2025-11-07 00:15:53.116051 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-07 00:15:53.479511 | controller -> localhost | changed
2025-11-07 00:15:53.492157 | 
2025-11-07 00:15:53.492254 | TASK [add-build-sshkey : Add back temp key]
2025-11-07 00:15:53.784432 | controller -> localhost | Identity added: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/b78007046b324289be6694b3cf93bcdd_id_ecdsa (zuul-build-sshkey)
2025-11-07 00:15:53.784628 | controller -> localhost | ok: Runtime: 0:00:00.007967
2025-11-07 00:15:53.793148 | 
2025-11-07 00:15:53.793216 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-07 00:15:53.998115 | controller | ok
2025-11-07 00:15:54.005363 | 
2025-11-07 00:15:54.005430 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-07 00:15:54.030979 | controller | skipping: Conditional result was False
2025-11-07 00:15:54.054244 | 
2025-11-07 00:15:54.054427 | TASK [include_role : remove-zuul-sshkey]
2025-11-07 00:15:54.079416 | controller | skipping: Conditional result was False
2025-11-07 00:15:54.085902 | 
2025-11-07 00:15:54.085972 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-07 00:15:54.302160 | controller | ok: "logs"
2025-11-07 00:15:54.302398 | controller | ok: All items complete
2025-11-07 00:15:54.302427 | 
2025-11-07 00:15:54.486488 | controller | ok: "artifacts"
2025-11-07 00:15:54.674568 | controller | ok: "docs"
2025-11-07 00:15:54.687659 | 
2025-11-07 00:15:54.687830 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-07 00:15:54.926843 | controller | changed: "logs"
2025-11-07 00:15:55.124166 | controller | changed: "artifacts"
2025-11-07 00:15:55.310000 | controller | changed: "docs"
2025-11-07 00:15:55.387708 | 
2025-11-07 00:15:55.387829 | PLAY RECAP
2025-11-07 00:15:55.387879 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-07 00:15:55.387906 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-07 00:15:55.387925 | 
2025-11-07 00:15:55.535120 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-07 00:15:55.536006 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-07 00:15:56.167680 | 
2025-11-07 00:15:56.167825 | PLAY [all]
2025-11-07 00:15:56.193921 | 
2025-11-07 00:15:56.194041 | TASK [Install binary dependencies]
2025-11-07 00:15:56.243619 | controller | ok
2025-11-07 00:15:56.265441 | 
2025-11-07 00:15:56.265563 | TASK [bindep : Include find tasks]
2025-11-07 00:15:56.304729 | controller | ok
2025-11-07 00:15:56.312827 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-07 00:15:56.319220 | 
2025-11-07 00:15:56.319285 | TASK [bindep : Look for bindep.txt]
2025-11-07 00:15:56.747275 | controller | ok
2025-11-07 00:15:56.757171 | 
2025-11-07 00:15:56.757275 | TASK [bindep : Define bindep_file fact]
2025-11-07 00:15:56.782150 | controller | skipping: Conditional result was False
2025-11-07 00:15:56.788199 | 
2025-11-07 00:15:56.788272 | TASK [bindep : Look for other-requirements.txt]
2025-11-07 00:15:57.016873 | controller | ok
2025-11-07 00:15:57.028874 | 
2025-11-07 00:15:57.028981 | TASK [bindep : Define bindep_file fact]
2025-11-07 00:15:57.066846 | controller | skipping: Conditional result was False
2025-11-07 00:15:57.073564 | 
2025-11-07 00:15:57.073636 | TASK [bindep : Look for bindep fallback file]
2025-11-07 00:15:57.098260 | controller | skipping: Conditional result was False
2025-11-07 00:15:57.105606 | 
2025-11-07 00:15:57.105685 | TASK [bindep : Define bindep_file fact]
2025-11-07 00:15:57.131411 | controller | skipping: Conditional result was False
2025-11-07 00:15:57.140561 | 
2025-11-07 00:15:57.140669 | TASK [bindep : Include bindep tasks]
2025-11-07 00:15:57.164206 | controller | skipping: Conditional result was False
2025-11-07 00:15:57.170482 | 
2025-11-07 00:15:57.170548 | TASK [bindep : Include install tasks]
2025-11-07 00:15:57.194169 | controller | skipping: Conditional result was False
2025-11-07 00:15:57.202164 | 
2025-11-07 00:15:57.202243 | LOOP [bindep : Include package tasks]
2025-11-07 00:15:57.267752 | 
2025-11-07 00:15:57.267910 | TASK [Run test-setup role]
2025-11-07 00:15:57.288478 | controller | ok
2025-11-07 00:15:57.306010 | 
2025-11-07 00:15:57.306154 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-07 00:15:57.520919 | controller | ok
2025-11-07 00:15:57.528060 | 
2025-11-07 00:15:57.528131 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-07 00:15:58.066218 | controller | skipping: Conditional result was False
2025-11-07 00:15:58.110288 | 
2025-11-07 00:15:58.110462 | PLAY RECAP
2025-11-07 00:15:58.110525 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-07 00:15:58.110556 | 
2025-11-07 00:15:58.265559 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-07 00:15:58.266440 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-07 00:15:58.845572 | 
2025-11-07 00:15:58.845695 | PLAY [controller]
2025-11-07 00:15:58.865426 | 
2025-11-07 00:15:58.865513 | TASK [Create the /root directory]
2025-11-07 00:15:59.213072 | controller | ok
2025-11-07 00:15:59.218843 | 
2025-11-07 00:15:59.218967 | TASK [Install glibc-langpack-en]
2025-11-07 00:16:03.088437 | controller | ok: Nothing to do
2025-11-07 00:16:03.103656 | 
2025-11-07 00:16:03.103832 | TASK [Ensure controller directory exists]
2025-11-07 00:16:03.339348 | controller | changed
2025-11-07 00:16:03.347713 | 
2025-11-07 00:16:03.347798 | TASK [Install container runtime]
2025-11-07 00:16:03.417568 | controller | ok
2025-11-07 00:16:03.470520 | 
2025-11-07 00:16:03.470657 | LOOP [ensure-podman : Find distribution installation]
2025-11-07 00:16:03.500944 | controller | ok: "/var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-07 00:16:03.515491 | controller | included: /var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-07 00:16:03.524987 | 
2025-11-07 00:16:03.525102 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-07 00:17:08.808103 | controller | changed
2025-11-07 00:17:08.818376 | 
2025-11-07 00:17:08.818518 | TASK [ensure-podman : Fetch podman version]
2025-11-07 00:17:09.367701 | controller | Client:       Podman Engine
2025-11-07 00:17:09.367818 | controller | Version:      4.6.2
2025-11-07 00:17:09.367891 | controller | API Version:  4.6.2
2025-11-07 00:17:09.367936 | controller | Go Version:   go1.19.12
2025-11-07 00:17:09.367991 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-07 00:17:09.368036 | controller | OS/Arch:      linux/amd64
2025-11-07 00:17:09.866188 | controller | ok: Runtime: 0:00:00.208222
2025-11-07 00:17:09.883961 | 
2025-11-07 00:17:09.884194 | TASK [ensure-podman : Print podman version installed]
2025-11-07 00:17:09.928525 | Podman version: Client:       Podman Engine
2025-11-07 00:17:09.928920 | Version:      4.6.2
2025-11-07 00:17:09.929011 | API Version:  4.6.2
2025-11-07 00:17:09.929125 | Go Version:   go1.19.12
2025-11-07 00:17:09.929182 | Built:        Mon Aug 28 19:38:31 2023
2025-11-07 00:17:09.929236 | OS/Arch:      linux/amd64
2025-11-07 00:17:09.948305 | 
2025-11-07 00:17:09.948537 | TASK [ensure-podman : Validate podman engine]
2025-11-07 00:17:10.507159 | controller | skipping: Conditional result was False
2025-11-07 00:17:10.515839 | 
2025-11-07 00:17:10.515958 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-07 00:17:10.541578 | controller | skipping: Conditional result was False
2025-11-07 00:17:10.557104 | 
2025-11-07 00:17:10.557255 | TASK [Ensure python3.8 is present]
2025-11-07 00:17:10.583693 | controller | skipping: Conditional result was False
2025-11-07 00:17:10.591913 | 
2025-11-07 00:17:10.592088 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-07 00:17:10.617888 | controller | ok
2025-11-07 00:17:10.644334 | 
2025-11-07 00:17:10.644486 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-07 00:17:12.152707 | controller | ok: Nothing to do
2025-11-07 00:17:12.158615 | 
2025-11-07 00:17:12.158678 | TASK [our-ensure-python : Also install python3-devel]
2025-11-07 00:17:21.291148 | controller | changed
2025-11-07 00:17:21.329640 | 
2025-11-07 00:17:21.329917 | TASK [Run ensure-virtualenv role]
2025-11-07 00:17:21.350730 | controller | ok
2025-11-07 00:17:21.373512 | 
2025-11-07 00:17:21.373618 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-07 00:17:21.580772 | controller | /usr/bin/virtualenv
2025-11-07 00:17:21.912319 | controller | ok: Runtime: 0:00:00.003572
2025-11-07 00:17:21.918688 | 
2025-11-07 00:17:21.918783 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-07 00:17:21.936325 | controller | skipping: Conditional result was False
2025-11-07 00:17:21.936573 | controller | ok: All items complete
2025-11-07 00:17:21.936600 | 
2025-11-07 00:17:21.953920 | 
2025-11-07 00:17:21.954044 | TASK [Find the full path of the Python interpreter]
2025-11-07 00:17:22.157248 | controller | /usr/bin/python3
2025-11-07 00:17:22.484458 | controller | ok
2025-11-07 00:17:22.497483 | 
2025-11-07 00:17:22.497650 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-07 00:17:23.421116 | controller | created virtual environment CPython3.11.0.final.0-64 in 498ms
2025-11-07 00:17:23.450862 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-07 00:17:23.451378 | 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-11-07 00:17:23.451586 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-07 00:17:23.451685 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-07 00:17:23.553157 | controller | changed
2025-11-07 00:17:23.569003 | 
2025-11-07 00:17:23.569222 | TASK [Set selinux package]
2025-11-07 00:17:23.610411 | controller | ok
2025-11-07 00:17:23.624320 | 
2025-11-07 00:17:23.624543 | TASK [Set selinux package (Fedora)]
2025-11-07 00:17:23.672113 | controller | ok
2025-11-07 00:17:23.681594 | 
2025-11-07 00:17:23.681726 | TASK [Install selinux into virtualenv]
2025-11-07 00:17:37.248372 | controller | Collecting selinux-please-lie-to-me
2025-11-07 00:17:49.510463 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-07 00:17:49.823891 | controller | Collecting setuptools<50.0.0
2025-11-07 00:17:49.828993 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-07 00:17:49.872465 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.6 MB/s eta 0:00:00
2025-11-07 00:17:49.951583 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-07 00:17:49.951798 | controller |   Attempting uninstall: setuptools
2025-11-07 00:17:49.954166 | controller |     Found existing installation: setuptools 62.6.0
2025-11-07 00:17:50.013653 | controller |     Uninstalling setuptools-62.6.0:
2025-11-07 00:17:50.021779 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-07 00:17:50.366973 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-07 00:18:01.920408 | controller |
2025-11-07 00:18:02.039654 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-07 00:18:02.039762 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-07 00:18:02.246289 | controller | ok: Runtime: 0:00:38.145849
2025-11-07 00:18:02.264271 | 
2025-11-07 00:18:02.264440 | TASK [Install pytest-forked into virtualenv]
2025-11-07 00:18:14.171848 | controller | Collecting pytest-forked
2025-11-07 00:18:24.462164 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-07 00:18:24.505004 | controller | Collecting py
2025-11-07 00:18:24.509481 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-07 00:18:24.531832 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.5 MB/s eta 0:00:00
2025-11-07 00:18:24.643720 | controller | Collecting pytest>=3.10
2025-11-07 00:18:24.648342 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-11-07 00:18:24.667166 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 22.7 MB/s eta 0:00:00
2025-11-07 00:18:24.706958 | controller | Collecting iniconfig>=1
2025-11-07 00:18:24.710416 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-07 00:18:24.758486 | controller | Collecting packaging>=20
2025-11-07 00:18:24.762153 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-07 00:18:24.772385 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.8 MB/s eta 0:00:00
2025-11-07 00:18:24.807113 | controller | Collecting pluggy<2,>=1.5
2025-11-07 00:18:24.810533 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-07 00:18:24.864028 | controller | Collecting pygments>=2.7.2
2025-11-07 00:18:24.867536 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-07 00:18:24.891358 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 58.0 MB/s eta 0:00:00
2025-11-07 00:18:24.962470 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-07 00:18:26.018225 | controller | Successfully installed iniconfig-2.3.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-11-07 00:18:26.027116 | controller |
2025-11-07 00:18:26.100401 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-07 00:18:26.100444 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-07 00:18:26.342000 | controller | ok: Runtime: 0:00:23.582637
2025-11-07 00:18:26.363144 | 
2025-11-07 00:18:26.363374 | TASK [Update pip]
2025-11-07 00:18:26.966474 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-07 00:18:36.832073 | controller | Collecting pip
2025-11-07 00:19:01.100374 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-07 00:19:01.154411 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 36.3 MB/s eta 0:00:00
2025-11-07 00:19:01.217837 | controller | Installing collected packages: pip
2025-11-07 00:19:01.217942 | controller |   Attempting uninstall: pip
2025-11-07 00:19:01.220079 | controller |     Found existing installation: pip 22.2.2
2025-11-07 00:19:01.355939 | controller |     Uninstalling pip-22.2.2:
2025-11-07 00:19:01.371086 | controller |       Successfully uninstalled pip-22.2.2
2025-11-07 00:19:02.166851 | controller | Successfully installed pip-25.3
2025-11-07 00:19:02.527297 | controller | ok: Runtime: 0:00:35.571238
2025-11-07 00:19:02.535987 | 
2025-11-07 00:19:02.536149 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-07 00:19:02.755436 | controller | changed
2025-11-07 00:19:02.765645 | 
2025-11-07 00:19:02.765792 | TASK [Install ansible into virtualenv]
2025-11-07 00:19:03.292784 | controller | Processing ./src/github.com/ansible/ansible
2025-11-07 00:19:03.296071 | controller |   Installing build dependencies: started
2025-11-07 00:19:28.501606 | controller |   Installing build dependencies: finished with status 'done'
2025-11-07 00:19:28.502821 | controller |   Getting requirements to build wheel: started
2025-11-07 00:19:29.233504 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-07 00:19:29.235424 | controller |   Preparing metadata (pyproject.toml): started
2025-11-07 00:19:29.704925 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-07 00:19:29.710262 | 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-11-07 00:19:29.715778 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-07 00:19:29.842731 | controller | ERROR
2025-11-07 00:19:29.842967 | controller | {
2025-11-07 00:19:29.843073 | controller |   "delta": "0:00:26.764142",
2025-11-07 00:19:29.843128 | controller |   "end": "2025-11-07 00:19:29.776769",
2025-11-07 00:19:29.843173 | controller |   "msg": "non-zero return code",
2025-11-07 00:19:29.843232 | controller |   "rc": 1,
2025-11-07 00:19:29.843272 | controller |   "start": "2025-11-07 00:19:03.012627"
2025-11-07 00:19:29.843310 | controller | }
failure
2025-11-07 00:19:29.846247 | 
2025-11-07 00:19:29.846349 | PLAY RECAP
2025-11-07 00:19:29.846431 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-07 00:19:29.846474 | 
2025-11-07 00:19:29.992351 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-07 00:19:29.993995 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-07 00:19:30.656952 | 
2025-11-07 00:19:30.657114 | PLAY [all]
2025-11-07 00:19:30.689827 | 
2025-11-07 00:19:30.689964 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-07 00:19:30.933798 | controller | changed: non-zero return code
2025-11-07 00:19:30.939545 | 
2025-11-07 00:19:30.939619 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-07 00:19:30.964067 | controller | skipping: Conditional result was False
2025-11-07 00:19:30.970341 | 
2025-11-07 00:19:30.970414 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-07 00:19:31.006174 | 
2025-11-07 00:19:31.006396 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-07 00:19:31.031515 | 
2025-11-07 00:19:31.031735 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-07 00:19:31.047263 | controller | skipping: Conditional result was False
2025-11-07 00:19:31.058751 | 
2025-11-07 00:19:31.058859 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-07 00:19:31.085171 | 
2025-11-07 00:19:31.085395 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-07 00:19:31.102043 | controller | skipping: Conditional result was False
2025-11-07 00:19:31.111420 | 
2025-11-07 00:19:31.111520 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-07 00:19:31.128301 | controller | skipping: Conditional result was False
2025-11-07 00:19:31.138201 | 
2025-11-07 00:19:31.138308 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-07 00:19:31.154555 | controller | skipping: Conditional result was False
2025-11-07 00:19:31.196277 | 
2025-11-07 00:19:31.196390 | PLAY RECAP
2025-11-07 00:19:31.196523 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-07 00:19:31.196552 | 
2025-11-07 00:19:31.307320 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-07 00:19:31.309139 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-07 00:19:31.930798 | 
2025-11-07 00:19:31.930991 | PLAY [all:!appliance*]
2025-11-07 00:19:31.955319 | 
2025-11-07 00:19:31.955417 | TASK [unregister the node]
2025-11-07 00:19:32.486875 | controller | skipping: Conditional result was False
2025-11-07 00:19:32.493190 | 
2025-11-07 00:19:32.493271 | TASK [include_role : fetch-output]
2025-11-07 00:19:32.543869 | controller | ok
2025-11-07 00:19:32.564440 | 
2025-11-07 00:19:32.564550 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-07 00:19:32.619262 | controller | skipping: Conditional result was False
2025-11-07 00:19:32.625882 | 
2025-11-07 00:19:32.625971 | TASK [fetch-output : Set log path for single node]
2025-11-07 00:19:32.666857 | controller | ok
2025-11-07 00:19:32.672530 | 
2025-11-07 00:19:32.672596 | LOOP [fetch-output : Ensure local output dirs]
2025-11-07 00:19:33.166257 | controller -> localhost | ok: "/var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/logs"
2025-11-07 00:19:33.444507 | controller -> localhost | changed: "/var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/artifacts"
2025-11-07 00:19:33.692527 | controller -> localhost | changed: "/var/lib/zuul/builds/b78007046b324289be6694b3cf93bcdd/work/docs"
2025-11-07 00:19:33.713966 | 
2025-11-07 00:19:33.714148 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-07 00:19:34.458037 | controller | changed:
2025-11-07 00:19:34.458379 | controller | .d..t...... ./
2025-11-07 00:19:34.458419 | controller | cd+++++++++ controller/
2025-11-07 00:19:34.458465 | controller | changed: All items complete
2025-11-07 00:19:34.458492 | 
2025-11-07 00:19:35.013800 | controller | changed: .d..t...... ./
2025-11-07 00:19:35.559572 | controller | changed: .d..t...... ./
2025-11-07 00:19:35.589417 | 
2025-11-07 00:19:35.589576 | TASK [include_role : fetch-output-openshift]
2025-11-07 00:19:35.604643 | controller | skipping: Conditional result was False
2025-11-07 00:19:35.614338 | 
2025-11-07 00:19:35.614466 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-07 00:19:35.640804 | controller | skipping: Conditional result was False
2025-11-07 00:19:35.650267 | controller | skipping: Conditional result was False
2025-11-07 00:19:35.700581 | 
2025-11-07 00:19:35.700712 | PLAY [localhost]
2025-11-07 00:19:35.717378 | 
2025-11-07 00:19:35.717493 | TASK [Run Zuul manifest role]
2025-11-07 00:19:35.737887 | localhost | ok
2025-11-07 00:19:35.752072 | 
2025-11-07 00:19:35.752153 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-07 00:19:36.213684 | localhost | changed
2025-11-07 00:19:36.225236 | 
2025-11-07 00:19:36.225386 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-07 00:19:36.263780 | localhost | ok
2025-11-07 00:19:36.283957 | 
2025-11-07 00:19:36.284151 | TASK [Set zuul-log-path fact]
2025-11-07 00:19:36.308584 | localhost | ok
2025-11-07 00:19:36.330453 | 
2025-11-07 00:19:36.330585 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-07 00:19:36.362252 | localhost | ok
2025-11-07 00:19:36.375486 | 
2025-11-07 00:19:36.375628 | LOOP [Run upload-logs-swift role]
2025-11-07 00:19:36.421812 | localhost | Output suppressed because no_log was given
2025-11-07 00:19:36.461464 | 
2025-11-07 00:19:36.461766 | TASK [Set zuul-log-path fact]
2025-11-07 00:19:36.507868 | localhost | skipping: Conditional result was False
2025-11-07 00:19:36.518618 | 
2025-11-07 00:19:36.518763 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-07 00:19:37.047612 | localhost -> localhost | ok: Runtime: 0:00:00.005424
2025-11-07 00:19:37.060008 | 
2025-11-07 00:19:37.060187 | TASK [upload-logs-swift : Upload logs to swift]