2025-12-19 00:06:33.879365 | Job console starting... 2025-12-19 00:06:33.890215 | Updating repositories 2025-12-19 00:06:34.063884 | Preparing job workspace 2025-12-19 00:06:38.887179 | Running Ansible setup... 2025-12-19 00:06:43.706073 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-19 00:06:44.296417 | 2025-12-19 00:06:44.296559 | PLAY [localhost] 2025-12-19 00:06:44.305352 | 2025-12-19 00:06:44.305456 | TASK [Gathering Facts] 2025-12-19 00:06:45.353309 | localhost | ok 2025-12-19 00:06:45.371256 | 2025-12-19 00:06:45.371402 | TASK [Setup log path fact] 2025-12-19 00:06:45.391411 | localhost | ok 2025-12-19 00:06:45.405792 | 2025-12-19 00:06:45.405904 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-19 00:06:45.433922 | localhost | ok 2025-12-19 00:06:45.442314 | 2025-12-19 00:06:45.442417 | TASK [emit-job-header : Print job information] 2025-12-19 00:06:45.473629 | # Job Information 2025-12-19 00:06:45.473896 | Ansible Version: 2.15.12 2025-12-19 00:06:45.473943 | Job: ansible-test-sanity-docker-devel 2025-12-19 00:06:45.473974 | Pipeline: periodic 2025-12-19 00:06:45.474001 | Executor: ze04.softwarefactory-project.io 2025-12-19 00:06:45.474029 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-19 00:06:45.474060 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/fe5/ansible/fe5bd1e2e4b74cd7819a74dfc381b6f0/ 2025-12-19 00:06:45.474089 | Event ID: 5e57919544954c60be3d868aae791c40 2025-12-19 00:06:45.479259 | 2025-12-19 00:06:45.479381 | LOOP [emit-job-header : Print node information] 2025-12-19 00:06:45.581816 | localhost | ok: 2025-12-19 00:06:45.582067 | localhost | # Node Information 2025-12-19 00:06:45.582111 | localhost | Inventory Hostname: controller 2025-12-19 00:06:45.582144 | localhost | Hostname: np0005566430 2025-12-19 00:06:45.582176 | localhost | Username: zuul 2025-12-19 00:06:45.582213 | localhost | Distro: Fedora 37 2025-12-19 00:06:45.582244 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-19 00:06:45.582274 | localhost | Region: ca-ymq-1 2025-12-19 00:06:45.582302 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-19 00:06:45.582332 | localhost | Product Name: OpenStack Nova 2025-12-19 00:06:45.582361 | localhost | Interface IP: 162.253.55.49 2025-12-19 00:06:45.598081 | 2025-12-19 00:06:45.598204 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-19 00:06:46.022891 | localhost -> localhost | changed 2025-12-19 00:06:46.033101 | 2025-12-19 00:06:46.033256 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-19 00:06:47.213233 | localhost -> localhost | changed 2025-12-19 00:06:47.276826 | 2025-12-19 00:06:47.276920 | PLAY [all:!appliance*] 2025-12-19 00:06:47.295289 | 2025-12-19 00:06:47.295371 | TASK [include_role : start-zuul-console] 2025-12-19 00:06:47.317169 | controller | ok 2025-12-19 00:06:47.331521 | 2025-12-19 00:06:47.331598 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-19 00:06:47.741732 | controller | ok 2025-12-19 00:06:47.753358 | 2025-12-19 00:06:47.753455 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-19 00:07:10.422513 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-19 00:07:10.438652 | 2025-12-19 00:07:10.439010 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-19 00:07:10.999510 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.015131 | 2025-12-19 00:07:11.015323 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-19 00:07:11.044395 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.061739 | 2025-12-19 00:07:11.061933 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-19 00:07:11.088454 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.112004 | 2025-12-19 00:07:11.112270 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-19 00:07:11.148391 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.157865 | 2025-12-19 00:07:11.158008 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-19 00:07:11.185174 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.195469 | 2025-12-19 00:07:11.195603 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-19 00:07:11.219985 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.235648 | 2025-12-19 00:07:11.235786 | TASK [Disable Fedora Modular] 2025-12-19 00:07:11.635430 | controller | changed 2025-12-19 00:07:11.650775 | 2025-12-19 00:07:11.650936 | TASK [Enable EPEL] 2025-12-19 00:07:11.677105 | controller | skipping: Conditional result was False 2025-12-19 00:07:11.686462 | 2025-12-19 00:07:11.686563 | TASK [Register the RHEL node] 2025-12-19 00:07:12.242399 | 2025-12-19 00:07:12.242580 | TASK [Show the subscription-manager status] 2025-12-19 00:07:12.788880 | controller | skipping: Conditional result was False 2025-12-19 00:07:12.811388 | 2025-12-19 00:07:12.811547 | TASK [Enable EPEL on RHEL] 2025-12-19 00:07:13.374491 | controller | skipping: Conditional result was False 2025-12-19 00:07:13.385395 | 2025-12-19 00:07:13.385531 | TASK [Install git and tox] 2025-12-19 00:08:13.396207 | controller | changed 2025-12-19 00:08:13.411094 | 2025-12-19 00:08:13.411260 | TASK [include_role : prepare-workspace] 2025-12-19 00:08:13.441128 | controller | ok 2025-12-19 00:08:13.478956 | 2025-12-19 00:08:13.479099 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-19 00:08:13.734887 | controller | ok 2025-12-19 00:08:13.750824 | 2025-12-19 00:08:13.750993 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-19 00:08:28.504322 | controller | Output suppressed because no_log was given 2025-12-19 00:08:28.518520 | 2025-12-19 00:08:28.518621 | TASK [include_role : prepare-workspace-openshift] 2025-12-19 00:08:28.544241 | controller | skipping: Conditional result was False 2025-12-19 00:08:28.570932 | 2025-12-19 00:08:28.571033 | PLAY [all:!appliance] 2025-12-19 00:08:28.589351 | 2025-12-19 00:08:28.589448 | TASK [Run add-build-sshkey role (RSA)] 2025-12-19 00:08:28.622234 | controller | ok 2025-12-19 00:08:28.672778 | 2025-12-19 00:08:28.672976 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-19 00:08:28.921741 | controller -> localhost | ok 2025-12-19 00:08:28.928655 | 2025-12-19 00:08:28.928749 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-19 00:08:28.983735 | controller | ok 2025-12-19 00:08:29.006021 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-19 00:08:29.016356 | 2025-12-19 00:08:29.016445 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-19 00:08:29.730308 | controller -> localhost | Generating public/private rsa key pair. 2025-12-19 00:08:29.730517 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_rsa. 2025-12-19 00:08:29.730560 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_rsa.pub. 2025-12-19 00:08:29.730607 | controller -> localhost | The key fingerprint is: 2025-12-19 00:08:29.730636 | controller -> localhost | SHA256:exR3ISZ+Iy60fkUSWSBNWQr7plIbDKKIOuO6dzLKNYY zuul-build-sshkey 2025-12-19 00:08:29.730664 | controller -> localhost | The key's randomart image is: 2025-12-19 00:08:29.730704 | controller -> localhost | +---[RSA 2048]----+ 2025-12-19 00:08:29.730725 | controller -> localhost | | oo=*= . | 2025-12-19 00:08:29.730745 | controller -> localhost | | =+= . . | 2025-12-19 00:08:29.730763 | controller -> localhost | | . . o * = . | 2025-12-19 00:08:29.730786 | controller -> localhost | |.. . . + + B o | 2025-12-19 00:08:29.730811 | controller -> localhost | |o . S = . | 2025-12-19 00:08:29.730846 | controller -> localhost | |. . o O . | 2025-12-19 00:08:29.730875 | controller -> localhost | |+E + . = o | 2025-12-19 00:08:29.730899 | controller -> localhost | |oo* o . o | 2025-12-19 00:08:29.730918 | controller -> localhost | |=* + | 2025-12-19 00:08:29.730939 | controller -> localhost | +----[SHA256]-----+ 2025-12-19 00:08:29.730988 | controller -> localhost | ok: Runtime: 0:00:00.355196 2025-12-19 00:08:29.737782 | 2025-12-19 00:08:29.737846 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-19 00:08:29.757869 | controller | ok 2025-12-19 00:08:29.768571 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-19 00:08:29.778694 | 2025-12-19 00:08:29.778772 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-19 00:08:29.802992 | controller | skipping: Conditional result was False 2025-12-19 00:08:29.809264 | 2025-12-19 00:08:29.809329 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-19 00:08:30.188817 | controller | changed 2025-12-19 00:08:30.199424 | 2025-12-19 00:08:30.199727 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-19 00:08:30.450929 | controller | ok 2025-12-19 00:08:30.461206 | 2025-12-19 00:08:30.461319 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-19 00:08:31.118084 | controller | changed 2025-12-19 00:08:31.127032 | 2025-12-19 00:08:31.127128 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-19 00:08:31.750761 | controller | changed 2025-12-19 00:08:31.757951 | 2025-12-19 00:08:31.758090 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-19 00:08:31.782549 | controller | skipping: Conditional result was False 2025-12-19 00:08:31.789618 | 2025-12-19 00:08:31.789765 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-19 00:08:32.172208 | controller -> localhost | changed 2025-12-19 00:08:32.185637 | 2025-12-19 00:08:32.185806 | TASK [add-build-sshkey : Add back temp key] 2025-12-19 00:08:32.487800 | controller -> localhost | Identity added: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_rsa (zuul-build-sshkey) 2025-12-19 00:08:32.488067 | controller -> localhost | ok: Runtime: 0:00:00.013874 2025-12-19 00:08:32.498152 | 2025-12-19 00:08:32.498254 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-19 00:08:32.857967 | controller | ok 2025-12-19 00:08:32.864056 | 2025-12-19 00:08:32.864146 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-19 00:08:32.888723 | controller | skipping: Conditional result was False 2025-12-19 00:08:32.901336 | 2025-12-19 00:08:32.901440 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-19 00:08:32.931826 | controller | ok 2025-12-19 00:08:32.949953 | 2025-12-19 00:08:32.950048 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-19 00:08:33.209655 | controller -> localhost | ok 2025-12-19 00:08:33.228598 | 2025-12-19 00:08:33.228942 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-19 00:08:33.267231 | controller | ok 2025-12-19 00:08:33.285247 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-19 00:08:33.295355 | 2025-12-19 00:08:33.295466 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-19 00:08:33.632128 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-19 00:08:33.632578 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_ecdsa. 2025-12-19 00:08:33.632668 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_ecdsa.pub. 2025-12-19 00:08:33.632798 | controller -> localhost | The key fingerprint is: 2025-12-19 00:08:33.632866 | controller -> localhost | SHA256:Dj3+LWsGPrjp4SU9iORaEUbcS6po2QjVX1oU/cHjhXg zuul-build-sshkey 2025-12-19 00:08:33.632922 | controller -> localhost | The key's randomart image is: 2025-12-19 00:08:33.632980 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-19 00:08:33.633033 | controller -> localhost | | o.. .oo o . | 2025-12-19 00:08:33.633085 | controller -> localhost | | ..o o o o E . | 2025-12-19 00:08:33.633135 | controller -> localhost | | . o+ = + + | 2025-12-19 00:08:33.633188 | controller -> localhost | |. ...+. o | 2025-12-19 00:08:33.633239 | controller -> localhost | |..+.o . S | 2025-12-19 00:08:33.633291 | controller -> localhost | |.+.+ o *.. | 2025-12-19 00:08:33.633340 | controller -> localhost | |. + +o*. | 2025-12-19 00:08:33.633421 | controller -> localhost | | o ..=oo+. | 2025-12-19 00:08:33.633476 | controller -> localhost | | . .=. +oo. | 2025-12-19 00:08:33.633532 | controller -> localhost | +----[SHA256]-----+ 2025-12-19 00:08:33.633747 | controller -> localhost | ok: Runtime: 0:00:00.015260 2025-12-19 00:08:33.649757 | 2025-12-19 00:08:33.649924 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-19 00:08:33.694762 | controller | ok 2025-12-19 00:08:33.706883 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-19 00:08:33.721242 | 2025-12-19 00:08:33.721435 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-19 00:08:33.747434 | controller | skipping: Conditional result was False 2025-12-19 00:08:33.758325 | 2025-12-19 00:08:33.758490 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-19 00:08:34.056483 | controller | changed 2025-12-19 00:08:34.070401 | 2025-12-19 00:08:34.070558 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-19 00:08:34.290459 | controller | ok 2025-12-19 00:08:34.299649 | 2025-12-19 00:08:34.300093 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-19 00:08:34.916759 | controller | changed 2025-12-19 00:08:34.927871 | 2025-12-19 00:08:34.927971 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-19 00:08:35.565814 | controller | changed 2025-12-19 00:08:35.584273 | 2025-12-19 00:08:35.584465 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-19 00:08:35.624299 | controller | skipping: Conditional result was False 2025-12-19 00:08:35.634187 | 2025-12-19 00:08:35.634292 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-19 00:08:35.873639 | controller -> localhost | changed 2025-12-19 00:08:35.893571 | 2025-12-19 00:08:35.893729 | TASK [add-build-sshkey : Add back temp key] 2025-12-19 00:08:36.193306 | controller -> localhost | Identity added: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/fe5bd1e2e4b74cd7819a74dfc381b6f0_id_ecdsa (zuul-build-sshkey) 2025-12-19 00:08:36.193552 | controller -> localhost | ok: Runtime: 0:00:00.012080 2025-12-19 00:08:36.200715 | 2025-12-19 00:08:36.200802 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-19 00:08:36.409361 | controller | ok 2025-12-19 00:08:36.418166 | 2025-12-19 00:08:36.418255 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-19 00:08:36.444551 | controller | skipping: Conditional result was False 2025-12-19 00:08:36.456874 | 2025-12-19 00:08:36.456945 | TASK [include_role : remove-zuul-sshkey] 2025-12-19 00:08:36.470538 | controller | skipping: Conditional result was False 2025-12-19 00:08:36.508445 | 2025-12-19 00:08:36.508568 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-19 00:08:36.729603 | controller | ok: "logs" 2025-12-19 00:08:36.730180 | controller | ok: All items complete 2025-12-19 00:08:36.730249 | 2025-12-19 00:08:36.901015 | controller | ok: "artifacts" 2025-12-19 00:08:37.091560 | controller | ok: "docs" 2025-12-19 00:08:37.101507 | 2025-12-19 00:08:37.101620 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-19 00:08:37.361122 | controller | changed: "logs" 2025-12-19 00:08:37.575508 | controller | changed: "artifacts" 2025-12-19 00:08:37.767383 | controller | changed: "docs" 2025-12-19 00:08:37.816017 | 2025-12-19 00:08:37.816102 | PLAY RECAP 2025-12-19 00:08:37.816157 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-19 00:08:37.816194 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-19 00:08:37.816219 | 2025-12-19 00:08:37.994909 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-19 00:08:37.995790 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-19 00:08:38.632476 | 2025-12-19 00:08:38.632586 | PLAY [all] 2025-12-19 00:08:38.655095 | 2025-12-19 00:08:38.655190 | TASK [Install binary dependencies] 2025-12-19 00:08:38.748838 | controller | ok 2025-12-19 00:08:38.781240 | 2025-12-19 00:08:38.781402 | TASK [bindep : Include find tasks] 2025-12-19 00:08:38.823428 | controller | ok 2025-12-19 00:08:38.832448 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-19 00:08:38.839647 | 2025-12-19 00:08:38.839732 | TASK [bindep : Look for bindep.txt] 2025-12-19 00:08:39.240584 | controller | ok 2025-12-19 00:08:39.255879 | 2025-12-19 00:08:39.256046 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:39.291739 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.301006 | 2025-12-19 00:08:39.301172 | TASK [bindep : Look for other-requirements.txt] 2025-12-19 00:08:39.524016 | controller | ok 2025-12-19 00:08:39.532637 | 2025-12-19 00:08:39.532775 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:39.559778 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.574072 | 2025-12-19 00:08:39.574229 | TASK [bindep : Look for bindep fallback file] 2025-12-19 00:08:39.608101 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.620850 | 2025-12-19 00:08:39.620971 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:39.647377 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.656527 | 2025-12-19 00:08:39.656716 | TASK [bindep : Include bindep tasks] 2025-12-19 00:08:39.684021 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.691818 | 2025-12-19 00:08:39.691909 | TASK [bindep : Include install tasks] 2025-12-19 00:08:39.719095 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.727928 | 2025-12-19 00:08:39.728099 | LOOP [bindep : Include package tasks] 2025-12-19 00:08:39.791008 | 2025-12-19 00:08:39.791203 | TASK [Run test-setup role] 2025-12-19 00:08:39.819655 | controller | ok 2025-12-19 00:08:39.842626 | 2025-12-19 00:08:39.842761 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-19 00:08:40.053978 | controller | ok 2025-12-19 00:08:40.070082 | 2025-12-19 00:08:40.070245 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-19 00:08:40.622086 | controller | skipping: Conditional result was False 2025-12-19 00:08:40.675033 | 2025-12-19 00:08:40.675123 | PLAY RECAP 2025-12-19 00:08:40.675176 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-19 00:08:40.675214 | 2025-12-19 00:08:40.782510 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-19 00:08:40.783372 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-19 00:08:41.418881 | 2025-12-19 00:08:41.419012 | PLAY [controller] 2025-12-19 00:08:41.440171 | 2025-12-19 00:08:41.440291 | TASK [Create the /root directory] 2025-12-19 00:08:41.881066 | controller | ok 2025-12-19 00:08:41.893660 | 2025-12-19 00:08:41.893815 | TASK [Install glibc-langpack-en] 2025-12-19 00:08:45.894209 | controller | ok: Nothing to do 2025-12-19 00:08:45.907868 | 2025-12-19 00:08:45.908001 | TASK [Ensure controller directory exists] 2025-12-19 00:08:46.125821 | controller | changed 2025-12-19 00:08:46.134512 | 2025-12-19 00:08:46.134637 | TASK [Install container runtime] 2025-12-19 00:08:46.189001 | controller | ok 2025-12-19 00:08:46.233650 | 2025-12-19 00:08:46.233822 | LOOP [ensure-podman : Find distribution installation] 2025-12-19 00:08:46.263049 | controller | ok: "/var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-19 00:08:46.285510 | controller | included: /var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-19 00:08:46.301522 | 2025-12-19 00:08:46.301778 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-19 00:09:54.014505 | controller | changed 2025-12-19 00:09:54.021761 | 2025-12-19 00:09:54.021836 | TASK [ensure-podman : Fetch podman version] 2025-12-19 00:09:54.528710 | controller | Client: Podman Engine 2025-12-19 00:09:54.550613 | controller | Version: 4.6.2 2025-12-19 00:09:54.550670 | controller | API Version: 4.6.2 2025-12-19 00:09:54.550685 | controller | Go Version: go1.19.12 2025-12-19 00:09:54.550715 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-19 00:09:54.550732 | controller | OS/Arch: linux/amd64 2025-12-19 00:09:54.584991 | controller | ok: Runtime: 0:00:00.183892 2025-12-19 00:09:54.593093 | 2025-12-19 00:09:54.593198 | TASK [ensure-podman : Print podman version installed] 2025-12-19 00:09:54.623376 | Podman version: Client: Podman Engine 2025-12-19 00:09:54.623543 | Version: 4.6.2 2025-12-19 00:09:54.623572 | API Version: 4.6.2 2025-12-19 00:09:54.623594 | Go Version: go1.19.12 2025-12-19 00:09:54.623612 | Built: Mon Aug 28 19:38:31 2023 2025-12-19 00:09:54.623660 | OS/Arch: linux/amd64 2025-12-19 00:09:54.629787 | 2025-12-19 00:09:54.629869 | TASK [ensure-podman : Validate podman engine] 2025-12-19 00:09:55.162859 | controller | skipping: Conditional result was False 2025-12-19 00:09:55.170594 | 2025-12-19 00:09:55.170694 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-19 00:09:55.194752 | controller | skipping: Conditional result was False 2025-12-19 00:09:55.208504 | 2025-12-19 00:09:55.208589 | TASK [Ensure python3.8 is present] 2025-12-19 00:09:55.234733 | controller | skipping: Conditional result was False 2025-12-19 00:09:55.241983 | 2025-12-19 00:09:55.242060 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-19 00:09:55.262182 | controller | ok 2025-12-19 00:09:55.285551 | 2025-12-19 00:09:55.285661 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-19 00:09:56.783212 | controller | ok: Nothing to do 2025-12-19 00:09:56.793391 | 2025-12-19 00:09:56.793705 | TASK [our-ensure-python : Also install python3-devel] 2025-12-19 00:10:08.731068 | controller | changed 2025-12-19 00:10:08.762237 | 2025-12-19 00:10:08.762484 | TASK [Run ensure-virtualenv role] 2025-12-19 00:10:08.788251 | controller | ok 2025-12-19 00:10:08.817042 | 2025-12-19 00:10:08.817156 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-19 00:10:09.031109 | controller | /usr/bin/virtualenv 2025-12-19 00:10:09.352240 | controller | ok: Runtime: 0:00:00.005154 2025-12-19 00:10:09.360655 | 2025-12-19 00:10:09.360928 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-19 00:10:09.403330 | controller | skipping: Conditional result was False 2025-12-19 00:10:09.403733 | controller | ok: All items complete 2025-12-19 00:10:09.403807 | 2025-12-19 00:10:09.421368 | 2025-12-19 00:10:09.421574 | TASK [Find the full path of the Python interpreter] 2025-12-19 00:10:09.693171 | controller | /usr/bin/python3 2025-12-19 00:10:10.019546 | controller | ok 2025-12-19 00:10:10.035936 | 2025-12-19 00:10:10.036139 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-19 00:10:10.917665 | controller | created virtual environment CPython3.11.0.final.0-64 in 516ms 2025-12-19 00:10:10.943290 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-19 00:10:10.943332 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2025-12-19 00:10:10.943341 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-19 00:10:10.943355 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-19 00:10:11.099237 | controller | changed 2025-12-19 00:10:11.110345 | 2025-12-19 00:10:11.110462 | TASK [Set selinux package] 2025-12-19 00:10:11.142761 | controller | ok 2025-12-19 00:10:11.153048 | 2025-12-19 00:10:11.153196 | TASK [Set selinux package (Fedora)] 2025-12-19 00:10:11.209501 | controller | ok 2025-12-19 00:10:11.217737 | 2025-12-19 00:10:11.217839 | TASK [Install selinux into virtualenv] 2025-12-19 00:10:48.677790 | controller | Collecting selinux-please-lie-to-me 2025-12-19 00:11:00.934877 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-19 00:11:01.255278 | controller | Collecting setuptools<50.0.0 2025-12-19 00:11:01.261384 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-19 00:11:01.297952 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.5 MB/s eta 0:00:00 2025-12-19 00:11:01.379220 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-19 00:11:01.379444 | controller | Attempting uninstall: setuptools 2025-12-19 00:11:01.381990 | controller | Found existing installation: setuptools 62.6.0 2025-12-19 00:11:01.442359 | controller | Uninstalling setuptools-62.6.0: 2025-12-19 00:11:01.450654 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-19 00:11:01.810328 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-19 00:11:13.304651 | controller | 2025-12-19 00:11:13.384354 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-19 00:11:13.384391 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-19 00:11:13.817877 | controller | ok: Runtime: 0:01:01.923205 2025-12-19 00:11:13.826852 | 2025-12-19 00:11:13.826954 | TASK [Install pytest-forked into virtualenv] 2025-12-19 00:11:25.550590 | controller | Collecting pytest-forked 2025-12-19 00:11:49.740036 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-19 00:11:49.785751 | controller | Collecting py 2025-12-19 00:11:49.791501 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-19 00:11:49.814269 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00 2025-12-19 00:11:49.927328 | controller | Collecting pytest>=3.10 2025-12-19 00:11:49.933483 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-19 00:11:49.948003 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.6 MB/s eta 0:00:00 2025-12-19 00:11:49.992498 | controller | Collecting iniconfig>=1.0.1 2025-12-19 00:11:49.996935 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-19 00:11:50.040375 | controller | Collecting packaging>=22 2025-12-19 00:11:50.043607 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-19 00:11:50.051306 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.4 MB/s eta 0:00:00 2025-12-19 00:11:50.083566 | controller | Collecting pluggy<2,>=1.5 2025-12-19 00:11:50.086766 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-19 00:11:50.141716 | controller | Collecting pygments>=2.7.2 2025-12-19 00:11:50.145882 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-19 00:11:50.164627 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 77.3 MB/s eta 0:00:00 2025-12-19 00:11:50.235177 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-19 00:11:51.287281 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2025-12-19 00:11:51.295820 | controller | 2025-12-19 00:11:51.364123 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-19 00:11:51.364156 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-19 00:11:51.414735 | controller | ok: Runtime: 0:00:37.314588 2025-12-19 00:11:51.428172 | 2025-12-19 00:11:51.428308 | TASK [Update pip] 2025-12-19 00:11:51.975255 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-19 00:12:04.388179 | controller | Collecting pip 2025-12-19 00:12:16.579522 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-19 00:12:16.659988 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 23.5 MB/s eta 0:00:00 2025-12-19 00:12:16.723845 | controller | Installing collected packages: pip 2025-12-19 00:12:16.724015 | controller | Attempting uninstall: pip 2025-12-19 00:12:16.726231 | controller | Found existing installation: pip 22.2.2 2025-12-19 00:12:16.860030 | controller | Uninstalling pip-22.2.2: 2025-12-19 00:12:16.874652 | controller | Successfully uninstalled pip-22.2.2 2025-12-19 00:12:17.707589 | controller | Successfully installed pip-25.3 2025-12-19 00:12:17.988783 | controller | ok: Runtime: 0:00:26.102965 2025-12-19 00:12:17.995353 | 2025-12-19 00:12:17.995417 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-19 00:12:18.224237 | controller | changed 2025-12-19 00:12:18.250647 | 2025-12-19 00:12:18.250894 | TASK [Install ansible into virtualenv] 2025-12-19 00:12:18.753326 | controller | Processing ./src/github.com/ansible/ansible 2025-12-19 00:12:18.756589 | controller | Installing build dependencies: started 2025-12-19 00:13:17.565401 | controller | Installing build dependencies: finished with status 'done' 2025-12-19 00:13:17.565996 | controller | Getting requirements to build wheel: started 2025-12-19 00:13:18.296132 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-19 00:13:18.297526 | controller | Preparing metadata (pyproject.toml): started 2025-12-19 00:13:18.760115 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-19 00:13:18.765854 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2025-12-19 00:13:18.772924 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-19 00:13:19.321125 | controller | ERROR 2025-12-19 00:13:19.321530 | controller | { 2025-12-19 00:13:19.321611 | controller | "delta": "0:01:00.379465", 2025-12-19 00:13:19.321667 | controller | "end": "2025-12-19 00:13:18.859270", 2025-12-19 00:13:19.321775 | controller | "msg": "non-zero return code", 2025-12-19 00:13:19.321850 | controller | "rc": 1, 2025-12-19 00:13:19.321900 | controller | "start": "2025-12-19 00:12:18.479805" 2025-12-19 00:13:19.321947 | controller | } failure 2025-12-19 00:13:19.324625 | 2025-12-19 00:13:19.324765 | PLAY RECAP 2025-12-19 00:13:19.324851 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-19 00:13:19.324898 | 2025-12-19 00:13:19.531013 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-19 00:13:19.532616 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-19 00:13:20.256760 | 2025-12-19 00:13:20.256930 | PLAY [all] 2025-12-19 00:13:20.281187 | 2025-12-19 00:13:20.281355 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-19 00:13:20.588555 | controller | changed: non-zero return code 2025-12-19 00:13:20.599120 | 2025-12-19 00:13:20.599293 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-19 00:13:20.626999 | controller | skipping: Conditional result was False 2025-12-19 00:13:20.635572 | 2025-12-19 00:13:20.635778 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-19 00:13:20.674038 | 2025-12-19 00:13:20.674327 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-19 00:13:20.711203 | 2025-12-19 00:13:20.711463 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-19 00:13:20.739096 | controller | skipping: Conditional result was False 2025-12-19 00:13:20.748582 | 2025-12-19 00:13:20.748726 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-19 00:13:20.782357 | 2025-12-19 00:13:20.782589 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-19 00:13:20.809014 | controller | skipping: Conditional result was False 2025-12-19 00:13:20.816506 | 2025-12-19 00:13:20.816587 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-19 00:13:20.842401 | controller | skipping: Conditional result was False 2025-12-19 00:13:20.849960 | 2025-12-19 00:13:20.850046 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-19 00:13:20.871394 | controller | skipping: Conditional result was False 2025-12-19 00:13:20.918802 | 2025-12-19 00:13:20.918947 | PLAY RECAP 2025-12-19 00:13:20.918999 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-19 00:13:20.919019 | 2025-12-19 00:13:21.046426 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-19 00:13:21.047433 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-19 00:13:21.691204 | 2025-12-19 00:13:21.691413 | PLAY [all:!appliance*] 2025-12-19 00:13:21.713985 | 2025-12-19 00:13:21.714105 | TASK [unregister the node] 2025-12-19 00:13:22.247195 | controller | skipping: Conditional result was False 2025-12-19 00:13:22.260936 | 2025-12-19 00:13:22.261177 | TASK [include_role : fetch-output] 2025-12-19 00:13:22.320398 | controller | ok 2025-12-19 00:13:22.373801 | 2025-12-19 00:13:22.373904 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-19 00:13:22.421199 | controller | skipping: Conditional result was False 2025-12-19 00:13:22.435552 | 2025-12-19 00:13:22.435768 | TASK [fetch-output : Set log path for single node] 2025-12-19 00:13:22.486002 | controller | ok 2025-12-19 00:13:22.498046 | 2025-12-19 00:13:22.498215 | LOOP [fetch-output : Ensure local output dirs] 2025-12-19 00:13:22.968040 | controller -> localhost | ok: "/var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/logs" 2025-12-19 00:13:23.244388 | controller -> localhost | changed: "/var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/artifacts" 2025-12-19 00:13:23.529126 | controller -> localhost | changed: "/var/lib/zuul/builds/fe5bd1e2e4b74cd7819a74dfc381b6f0/work/docs" 2025-12-19 00:13:23.542041 | 2025-12-19 00:13:23.542232 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-19 00:13:24.402749 | controller | changed: 2025-12-19 00:13:24.403481 | controller | .d..t...... ./ 2025-12-19 00:13:24.403560 | controller | cd+++++++++ controller/ 2025-12-19 00:13:24.403635 | controller | changed: All items complete 2025-12-19 00:13:24.403720 | 2025-12-19 00:13:24.961426 | controller | changed: .d..t...... ./ 2025-12-19 00:13:25.510362 | controller | changed: .d..t...... ./ 2025-12-19 00:13:25.542630 | 2025-12-19 00:13:25.542885 | TASK [include_role : fetch-output-openshift] 2025-12-19 00:13:25.561051 | controller | skipping: Conditional result was False 2025-12-19 00:13:25.575863 | 2025-12-19 00:13:25.576062 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-19 00:13:25.612060 | controller | skipping: Conditional result was False 2025-12-19 00:13:25.623937 | controller | skipping: Conditional result was False 2025-12-19 00:13:25.680639 | 2025-12-19 00:13:25.680801 | PLAY [localhost] 2025-12-19 00:13:25.695702 | 2025-12-19 00:13:25.695866 | TASK [Run Zuul manifest role] 2025-12-19 00:13:25.718169 | localhost | ok 2025-12-19 00:13:25.737606 | 2025-12-19 00:13:25.737932 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-19 00:13:26.177748 | localhost | changed 2025-12-19 00:13:26.184388 | 2025-12-19 00:13:26.184505 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-19 00:13:26.226197 | localhost | ok 2025-12-19 00:13:26.235456 | 2025-12-19 00:13:26.235516 | TASK [Set zuul-log-path fact] 2025-12-19 00:13:26.255881 | localhost | ok 2025-12-19 00:13:26.273130 | 2025-12-19 00:13:26.273303 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-19 00:13:26.303954 | localhost | ok 2025-12-19 00:13:26.312596 | 2025-12-19 00:13:26.312659 | LOOP [Run upload-logs-swift role] 2025-12-19 00:13:26.349067 | localhost | Output suppressed because no_log was given 2025-12-19 00:13:26.377474 | 2025-12-19 00:13:26.377581 | TASK [Set zuul-log-path fact] 2025-12-19 00:13:26.413417 | localhost | skipping: Conditional result was False 2025-12-19 00:13:26.421316 | 2025-12-19 00:13:26.421395 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-19 00:13:26.849943 | localhost -> localhost | ok: Runtime: 0:00:00.006921 2025-12-19 00:13:26.858630 | 2025-12-19 00:13:26.858865 | TASK [upload-logs-swift : Upload logs to swift]