2025-12-19 00:06:37.150901 | Job console starting... 2025-12-19 00:06:37.163501 | Updating repositories 2025-12-19 00:06:37.401150 | Preparing job workspace 2025-12-19 00:06:43.521954 | Running Ansible setup... 2025-12-19 00:06:48.747407 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-19 00:06:50.120499 | 2025-12-19 00:06:50.120639 | PLAY [localhost] 2025-12-19 00:06:50.130537 | 2025-12-19 00:06:50.130642 | TASK [Gathering Facts] 2025-12-19 00:06:51.695919 | localhost | ok 2025-12-19 00:06:51.723441 | 2025-12-19 00:06:51.723540 | TASK [Setup log path fact] 2025-12-19 00:06:51.761426 | localhost | ok 2025-12-19 00:06:51.774112 | 2025-12-19 00:06:51.774180 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-19 00:06:51.812268 | localhost | ok 2025-12-19 00:06:51.820812 | 2025-12-19 00:06:51.820891 | TASK [emit-job-header : Print job information] 2025-12-19 00:06:51.849346 | # Job Information 2025-12-19 00:06:51.849808 | Ansible Version: 2.15.12 2025-12-19 00:06:51.849841 | Job: ansible-test-sanity-docker-milestone 2025-12-19 00:06:51.849864 | Pipeline: periodic 2025-12-19 00:06:51.849883 | Executor: ze01.softwarefactory-project.io 2025-12-19 00:06:51.849901 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-19 00:06:51.849924 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/afa/ansible/afaae89b85904051be5b37eba44bc683/ 2025-12-19 00:06:51.849951 | Event ID: 5e57919544954c60be3d868aae791c40 2025-12-19 00:06:51.853944 | 2025-12-19 00:06:51.854009 | LOOP [emit-job-header : Print node information] 2025-12-19 00:06:51.964930 | localhost | ok: 2025-12-19 00:06:51.965138 | localhost | # Node Information 2025-12-19 00:06:51.965168 | localhost | Inventory Hostname: controller 2025-12-19 00:06:51.965191 | localhost | Hostname: np0005566431 2025-12-19 00:06:51.965213 | localhost | Username: zuul 2025-12-19 00:06:51.965237 | localhost | Distro: Fedora 37 2025-12-19 00:06:51.965258 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-19 00:06:51.965277 | localhost | Region: ca-ymq-1 2025-12-19 00:06:51.965296 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-19 00:06:51.965314 | localhost | Product Name: OpenStack Nova 2025-12-19 00:06:51.965333 | localhost | Interface IP: 162.253.55.209 2025-12-19 00:06:52.001695 | 2025-12-19 00:06:52.001840 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-19 00:06:52.458164 | localhost -> localhost | changed 2025-12-19 00:06:52.464943 | 2025-12-19 00:06:52.465040 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-19 00:06:53.390704 | localhost -> localhost | changed 2025-12-19 00:06:53.447773 | 2025-12-19 00:06:53.447908 | PLAY [all:!appliance*] 2025-12-19 00:06:53.472380 | 2025-12-19 00:06:53.472517 | TASK [include_role : start-zuul-console] 2025-12-19 00:06:53.502497 | controller | ok 2025-12-19 00:06:53.516820 | 2025-12-19 00:06:53.516903 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-19 00:06:53.885391 | controller | ok 2025-12-19 00:06:53.907989 | 2025-12-19 00:06:53.908176 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-19 00:07:16.469228 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-19 00:07:16.479725 | 2025-12-19 00:07:16.479854 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-19 00:07:17.021726 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.037096 | 2025-12-19 00:07:17.037278 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-19 00:07:17.065671 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.083343 | 2025-12-19 00:07:17.083539 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-19 00:07:17.112257 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.130390 | 2025-12-19 00:07:17.130714 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-19 00:07:17.158661 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.174652 | 2025-12-19 00:07:17.174831 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-19 00:07:17.202381 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.217480 | 2025-12-19 00:07:17.217633 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-19 00:07:17.245494 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.273972 | 2025-12-19 00:07:17.274123 | TASK [Disable Fedora Modular] 2025-12-19 00:07:17.692054 | controller | changed 2025-12-19 00:07:17.706175 | 2025-12-19 00:07:17.706314 | TASK [Enable EPEL] 2025-12-19 00:07:17.736197 | controller | skipping: Conditional result was False 2025-12-19 00:07:17.746281 | 2025-12-19 00:07:17.746372 | TASK [Register the RHEL node] 2025-12-19 00:07:18.300355 | 2025-12-19 00:07:18.300596 | TASK [Show the subscription-manager status] 2025-12-19 00:07:18.882322 | controller | skipping: Conditional result was False 2025-12-19 00:07:18.892489 | 2025-12-19 00:07:18.892593 | TASK [Enable EPEL on RHEL] 2025-12-19 00:07:19.438281 | controller | skipping: Conditional result was False 2025-12-19 00:07:19.451987 | 2025-12-19 00:07:19.452185 | TASK [Install git and tox] 2025-12-19 00:08:20.230478 | controller | changed 2025-12-19 00:08:20.243837 | 2025-12-19 00:08:20.243955 | TASK [include_role : prepare-workspace] 2025-12-19 00:08:20.277417 | controller | ok 2025-12-19 00:08:20.307059 | 2025-12-19 00:08:20.307176 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-19 00:08:20.571117 | controller | ok 2025-12-19 00:08:20.586224 | 2025-12-19 00:08:20.586361 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-19 00:08:34.597566 | controller | Output suppressed because no_log was given 2025-12-19 00:08:34.622668 | 2025-12-19 00:08:34.622780 | TASK [include_role : prepare-workspace-openshift] 2025-12-19 00:08:34.660978 | controller | skipping: Conditional result was False 2025-12-19 00:08:34.752805 | 2025-12-19 00:08:34.752882 | PLAY [all:!appliance] 2025-12-19 00:08:34.798226 | 2025-12-19 00:08:34.798335 | TASK [Run add-build-sshkey role (RSA)] 2025-12-19 00:08:34.821535 | controller | ok 2025-12-19 00:08:34.839060 | 2025-12-19 00:08:34.839156 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-19 00:08:35.098583 | controller -> localhost | ok 2025-12-19 00:08:35.113936 | 2025-12-19 00:08:35.114176 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-19 00:08:35.154000 | controller | ok 2025-12-19 00:08:35.183945 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-19 00:08:35.193263 | 2025-12-19 00:08:35.193543 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-19 00:08:35.742720 | controller -> localhost | Generating public/private rsa key pair. 2025-12-19 00:08:35.742934 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_rsa. 2025-12-19 00:08:35.742964 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_rsa.pub. 2025-12-19 00:08:35.742985 | controller -> localhost | The key fingerprint is: 2025-12-19 00:08:35.743006 | controller -> localhost | SHA256:0Y2R+h2yP+DVOQL02Rz9gkCTEVzGTgF867EOg0hKm2Q zuul-build-sshkey 2025-12-19 00:08:35.743056 | controller -> localhost | The key's randomart image is: 2025-12-19 00:08:35.743077 | controller -> localhost | +---[RSA 2048]----+ 2025-12-19 00:08:35.743096 | controller -> localhost | | +BO+. . | 2025-12-19 00:08:35.743115 | controller -> localhost | | .B*+ . .| 2025-12-19 00:08:35.743133 | controller -> localhost | | .oo*.* ..| 2025-12-19 00:08:35.743151 | controller -> localhost | | E . ..o O + .| 2025-12-19 00:08:35.743169 | controller -> localhost | | + = .So * = o | 2025-12-19 00:08:35.743197 | controller -> localhost | | + . . * * + | 2025-12-19 00:08:35.743220 | controller -> localhost | | . B . . | 2025-12-19 00:08:35.743239 | controller -> localhost | | . + | 2025-12-19 00:08:35.743257 | controller -> localhost | | . | 2025-12-19 00:08:35.743276 | controller -> localhost | +----[SHA256]-----+ 2025-12-19 00:08:35.743322 | controller -> localhost | ok: Runtime: 0:00:00.109422 2025-12-19 00:08:35.749791 | 2025-12-19 00:08:35.749878 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-19 00:08:35.790036 | controller | ok 2025-12-19 00:08:35.799964 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-19 00:08:35.808953 | 2025-12-19 00:08:35.809062 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-19 00:08:35.833580 | controller | skipping: Conditional result was False 2025-12-19 00:08:35.840150 | 2025-12-19 00:08:35.840246 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-19 00:08:36.302763 | controller | changed 2025-12-19 00:08:36.316299 | 2025-12-19 00:08:36.316442 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-19 00:08:36.585630 | controller | ok 2025-12-19 00:08:36.646281 | 2025-12-19 00:08:36.646349 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-19 00:08:37.320229 | controller | changed 2025-12-19 00:08:37.332960 | 2025-12-19 00:08:37.333169 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-19 00:08:37.927263 | controller | changed 2025-12-19 00:08:37.933271 | 2025-12-19 00:08:37.933332 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-19 00:08:37.947786 | controller | skipping: Conditional result was False 2025-12-19 00:08:37.954481 | 2025-12-19 00:08:37.954543 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-19 00:08:38.348183 | controller -> localhost | changed 2025-12-19 00:08:38.364939 | 2025-12-19 00:08:38.365095 | TASK [add-build-sshkey : Add back temp key] 2025-12-19 00:08:38.653680 | controller -> localhost | Identity added: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_rsa (zuul-build-sshkey) 2025-12-19 00:08:38.653914 | controller -> localhost | ok: Runtime: 0:00:00.014190 2025-12-19 00:08:38.660373 | 2025-12-19 00:08:38.660434 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-19 00:08:39.019387 | controller | ok 2025-12-19 00:08:39.029499 | 2025-12-19 00:08:39.029630 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-19 00:08:39.055517 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.080721 | 2025-12-19 00:08:39.080855 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-19 00:08:39.114731 | controller | ok 2025-12-19 00:08:39.144098 | 2025-12-19 00:08:39.144245 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-19 00:08:39.424689 | controller -> localhost | ok 2025-12-19 00:08:39.432768 | 2025-12-19 00:08:39.432837 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-19 00:08:39.463251 | controller | ok 2025-12-19 00:08:39.474080 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-19 00:08:39.480441 | 2025-12-19 00:08:39.480505 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-19 00:08:39.820599 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-19 00:08:39.820965 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_ecdsa. 2025-12-19 00:08:39.821089 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_ecdsa.pub. 2025-12-19 00:08:39.821177 | controller -> localhost | The key fingerprint is: 2025-12-19 00:08:39.821240 | controller -> localhost | SHA256:mhUvO9zv+rJmLkL/cu1YisYpUObuqk+oAOz0Zvm4YXg zuul-build-sshkey 2025-12-19 00:08:39.821299 | controller -> localhost | The key's randomart image is: 2025-12-19 00:08:39.821359 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-19 00:08:39.821420 | controller -> localhost | | | 2025-12-19 00:08:39.821481 | controller -> localhost | | | 2025-12-19 00:08:39.821537 | controller -> localhost | | . | 2025-12-19 00:08:39.821633 | controller -> localhost | |. o o | 2025-12-19 00:08:39.821702 | controller -> localhost | |.o + S . | 2025-12-19 00:08:39.821763 | controller -> localhost | |+ o.o o= + | 2025-12-19 00:08:39.821820 | controller -> localhost | |.o.E.+oo+.... | 2025-12-19 00:08:39.821877 | controller -> localhost | |..=.+ + Bo==. | 2025-12-19 00:08:39.821935 | controller -> localhost | |. .=++.+.OBB= | 2025-12-19 00:08:39.821996 | controller -> localhost | +----[SHA256]-----+ 2025-12-19 00:08:39.822167 | controller -> localhost | ok: Runtime: 0:00:00.013674 2025-12-19 00:08:39.838979 | 2025-12-19 00:08:39.839210 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-19 00:08:39.866194 | controller | ok 2025-12-19 00:08:39.881277 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-19 00:08:39.895209 | 2025-12-19 00:08:39.895363 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-19 00:08:39.912555 | controller | skipping: Conditional result was False 2025-12-19 00:08:39.920431 | 2025-12-19 00:08:39.920560 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-19 00:08:40.206556 | controller | changed 2025-12-19 00:08:40.222402 | 2025-12-19 00:08:40.222540 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-19 00:08:40.460215 | controller | ok 2025-12-19 00:08:40.473421 | 2025-12-19 00:08:40.473557 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-19 00:08:41.114625 | controller | changed 2025-12-19 00:08:41.128506 | 2025-12-19 00:08:41.128672 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-19 00:08:41.724470 | controller | changed 2025-12-19 00:08:41.742209 | 2025-12-19 00:08:41.742466 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-19 00:08:41.771223 | controller | skipping: Conditional result was False 2025-12-19 00:08:41.782155 | 2025-12-19 00:08:41.782277 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-19 00:08:42.084011 | controller -> localhost | changed 2025-12-19 00:08:42.097092 | 2025-12-19 00:08:42.097165 | TASK [add-build-sshkey : Add back temp key] 2025-12-19 00:08:42.469333 | controller -> localhost | Identity added: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/afaae89b85904051be5b37eba44bc683_id_ecdsa (zuul-build-sshkey) 2025-12-19 00:08:42.469611 | controller -> localhost | ok: Runtime: 0:00:00.013458 2025-12-19 00:08:42.510471 | 2025-12-19 00:08:42.510612 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-19 00:08:42.742317 | controller | ok 2025-12-19 00:08:42.754733 | 2025-12-19 00:08:42.754860 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-19 00:08:42.781414 | controller | skipping: Conditional result was False 2025-12-19 00:08:42.809720 | 2025-12-19 00:08:42.809873 | TASK [include_role : remove-zuul-sshkey] 2025-12-19 00:08:42.836789 | controller | skipping: Conditional result was False 2025-12-19 00:08:42.848035 | 2025-12-19 00:08:42.848140 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-19 00:08:43.087845 | controller | ok: "logs" 2025-12-19 00:08:43.088290 | controller | ok: All items complete 2025-12-19 00:08:43.088330 | 2025-12-19 00:08:43.288087 | controller | ok: "artifacts" 2025-12-19 00:08:43.478520 | controller | ok: "docs" 2025-12-19 00:08:43.498651 | 2025-12-19 00:08:43.498801 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-19 00:08:43.759389 | controller | changed: "logs" 2025-12-19 00:08:43.953963 | controller | changed: "artifacts" 2025-12-19 00:08:44.157530 | controller | changed: "docs" 2025-12-19 00:08:44.205805 | 2025-12-19 00:08:44.205916 | PLAY RECAP 2025-12-19 00:08:44.205973 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-19 00:08:44.205998 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-19 00:08:44.206037 | 2025-12-19 00:08:44.314244 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-19 00:08:44.316320 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-19 00:08:44.941715 | 2025-12-19 00:08:44.941882 | PLAY [all] 2025-12-19 00:08:44.965562 | 2025-12-19 00:08:44.965698 | TASK [Install binary dependencies] 2025-12-19 00:08:45.039069 | controller | ok 2025-12-19 00:08:45.063979 | 2025-12-19 00:08:45.064186 | TASK [bindep : Include find tasks] 2025-12-19 00:08:45.106213 | controller | ok 2025-12-19 00:08:45.115304 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-19 00:08:45.124105 | 2025-12-19 00:08:45.124306 | TASK [bindep : Look for bindep.txt] 2025-12-19 00:08:45.495254 | controller | ok 2025-12-19 00:08:45.505285 | 2025-12-19 00:08:45.505442 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:45.531230 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.540704 | 2025-12-19 00:08:45.540823 | TASK [bindep : Look for other-requirements.txt] 2025-12-19 00:08:45.774406 | controller | ok 2025-12-19 00:08:45.795547 | 2025-12-19 00:08:45.795745 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:45.823832 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.833946 | 2025-12-19 00:08:45.834114 | TASK [bindep : Look for bindep fallback file] 2025-12-19 00:08:45.860300 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.870904 | 2025-12-19 00:08:45.871050 | TASK [bindep : Define bindep_file fact] 2025-12-19 00:08:45.895791 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.911136 | 2025-12-19 00:08:45.911388 | TASK [bindep : Include bindep tasks] 2025-12-19 00:08:45.939639 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.950293 | 2025-12-19 00:08:45.950415 | TASK [bindep : Include install tasks] 2025-12-19 00:08:45.977477 | controller | skipping: Conditional result was False 2025-12-19 00:08:45.987569 | 2025-12-19 00:08:45.987751 | LOOP [bindep : Include package tasks] 2025-12-19 00:08:46.053636 | 2025-12-19 00:08:46.053937 | TASK [Run test-setup role] 2025-12-19 00:08:46.083222 | controller | ok 2025-12-19 00:08:46.109365 | 2025-12-19 00:08:46.109525 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-19 00:08:46.328589 | controller | ok 2025-12-19 00:08:46.337751 | 2025-12-19 00:08:46.337851 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-19 00:08:46.882657 | controller | skipping: Conditional result was False 2025-12-19 00:08:46.915689 | 2025-12-19 00:08:46.915827 | PLAY RECAP 2025-12-19 00:08:46.915882 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-19 00:08:46.915907 | 2025-12-19 00:08:47.034628 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-19 00:08:47.035526 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-19 00:08:47.682393 | 2025-12-19 00:08:47.682519 | PLAY [controller] 2025-12-19 00:08:47.703101 | 2025-12-19 00:08:47.703214 | TASK [Create the /root directory] 2025-12-19 00:08:48.142248 | controller | ok 2025-12-19 00:08:48.148543 | 2025-12-19 00:08:48.148694 | TASK [Install glibc-langpack-en] 2025-12-19 00:08:52.042271 | controller | ok: Nothing to do 2025-12-19 00:08:52.049886 | 2025-12-19 00:08:52.049989 | TASK [Ensure controller directory exists] 2025-12-19 00:08:52.268491 | controller | changed 2025-12-19 00:08:52.275376 | 2025-12-19 00:08:52.275449 | TASK [Install container runtime] 2025-12-19 00:08:52.340735 | controller | ok 2025-12-19 00:08:52.412530 | 2025-12-19 00:08:52.412784 | LOOP [ensure-podman : Find distribution installation] 2025-12-19 00:08:52.453376 | controller | ok: "/var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-19 00:08:52.476651 | controller | included: /var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-19 00:08:52.493319 | 2025-12-19 00:08:52.493627 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-19 00:10:09.994417 | controller | changed 2025-12-19 00:10:10.004783 | 2025-12-19 00:10:10.004927 | TASK [ensure-podman : Fetch podman version] 2025-12-19 00:10:10.564143 | controller | Client: Podman Engine 2025-12-19 00:10:10.564243 | controller | Version: 4.6.2 2025-12-19 00:10:10.564289 | controller | API Version: 4.6.2 2025-12-19 00:10:10.564331 | controller | Go Version: go1.19.12 2025-12-19 00:10:10.564423 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-19 00:10:10.564468 | controller | OS/Arch: linux/amd64 2025-12-19 00:10:11.055443 | controller | ok: Runtime: 0:00:00.195110 2025-12-19 00:10:11.064803 | 2025-12-19 00:10:11.064955 | TASK [ensure-podman : Print podman version installed] 2025-12-19 00:10:11.099144 | Podman version: Client: Podman Engine 2025-12-19 00:10:11.099336 | Version: 4.6.2 2025-12-19 00:10:11.099457 | API Version: 4.6.2 2025-12-19 00:10:11.099493 | Go Version: go1.19.12 2025-12-19 00:10:11.099520 | Built: Mon Aug 28 19:38:31 2023 2025-12-19 00:10:11.099550 | OS/Arch: linux/amd64 2025-12-19 00:10:11.108102 | 2025-12-19 00:10:11.108222 | TASK [ensure-podman : Validate podman engine] 2025-12-19 00:10:11.657121 | controller | skipping: Conditional result was False 2025-12-19 00:10:11.667609 | 2025-12-19 00:10:11.667746 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-19 00:10:11.693484 | controller | skipping: Conditional result was False 2025-12-19 00:10:11.710394 | 2025-12-19 00:10:11.710547 | TASK [Ensure python3.8 is present] 2025-12-19 00:10:11.725611 | controller | skipping: Conditional result was False 2025-12-19 00:10:11.735529 | 2025-12-19 00:10:11.735677 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-19 00:10:11.758667 | controller | ok 2025-12-19 00:10:11.786951 | 2025-12-19 00:10:11.787136 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-19 00:10:13.314062 | controller | ok: Nothing to do 2025-12-19 00:10:13.320286 | 2025-12-19 00:10:13.320417 | TASK [our-ensure-python : Also install python3-devel] 2025-12-19 00:10:25.920978 | controller | changed 2025-12-19 00:10:25.939537 | 2025-12-19 00:10:25.939704 | TASK [Run ensure-virtualenv role] 2025-12-19 00:10:25.964457 | controller | ok 2025-12-19 00:10:25.995181 | 2025-12-19 00:10:25.995313 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-19 00:10:26.277762 | controller | /usr/bin/virtualenv 2025-12-19 00:10:26.585318 | controller | ok: Runtime: 0:00:00.005011 2025-12-19 00:10:26.603139 | 2025-12-19 00:10:26.603306 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-19 00:10:26.628524 | controller | skipping: Conditional result was False 2025-12-19 00:10:26.628992 | controller | ok: All items complete 2025-12-19 00:10:26.629063 | 2025-12-19 00:10:26.657232 | 2025-12-19 00:10:26.657385 | TASK [Find the full path of the Python interpreter] 2025-12-19 00:10:26.878484 | controller | /usr/bin/python3 2025-12-19 00:10:27.201295 | controller | ok 2025-12-19 00:10:27.210901 | 2025-12-19 00:10:27.211042 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-19 00:10:28.118185 | controller | created virtual environment CPython3.11.0.final.0-64 in 438ms 2025-12-19 00:10:28.146516 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-19 00:10:28.146904 | 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:28.147076 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-19 00:10:28.147280 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-19 00:10:28.255817 | controller | changed 2025-12-19 00:10:28.263292 | 2025-12-19 00:10:28.263416 | TASK [Set selinux package] 2025-12-19 00:10:28.284766 | controller | ok 2025-12-19 00:10:28.290575 | 2025-12-19 00:10:28.290680 | TASK [Set selinux package (Fedora)] 2025-12-19 00:10:28.321984 | controller | ok 2025-12-19 00:10:28.329196 | 2025-12-19 00:10:28.329293 | TASK [Install selinux into virtualenv] 2025-12-19 00:10:53.824952 | controller | Collecting selinux-please-lie-to-me 2025-12-19 00:11:06.083396 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-19 00:11:06.386995 | controller | Collecting setuptools<50.0.0 2025-12-19 00:11:06.393899 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-19 00:11:06.427004 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.8 MB/s eta 0:00:00 2025-12-19 00:11:06.507512 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-19 00:11:06.507726 | controller | Attempting uninstall: setuptools 2025-12-19 00:11:06.510121 | controller | Found existing installation: setuptools 62.6.0 2025-12-19 00:11:06.568901 | controller | Uninstalling setuptools-62.6.0: 2025-12-19 00:11:06.576952 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-19 00:11:06.923936 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-19 00:11:18.450731 | controller | 2025-12-19 00:11:18.530431 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-19 00:11:18.530486 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-19 00:11:18.891560 | controller | ok: Runtime: 0:00:49.992590 2025-12-19 00:11:18.899999 | 2025-12-19 00:11:18.900140 | TASK [Install pytest-forked into virtualenv] 2025-12-19 00:11:28.652351 | controller | Collecting pytest-forked 2025-12-19 00:11:52.888579 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-19 00:11:52.935389 | controller | Collecting py 2025-12-19 00:11:52.940435 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-19 00:11:52.968180 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.0 MB/s eta 0:00:00 2025-12-19 00:11:53.072819 | controller | Collecting pytest>=3.10 2025-12-19 00:11:53.078489 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-19 00:11:53.098798 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 20.9 MB/s eta 0:00:00 2025-12-19 00:11:53.134675 | controller | Collecting iniconfig>=1.0.1 2025-12-19 00:11:53.138944 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-19 00:11:53.181633 | controller | Collecting packaging>=22 2025-12-19 00:11:53.184891 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-19 00:11:53.190255 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 19.4 MB/s eta 0:00:00 2025-12-19 00:11:53.225727 | controller | Collecting pluggy<2,>=1.5 2025-12-19 00:11:53.229225 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-19 00:11:53.280279 | controller | Collecting pygments>=2.7.2 2025-12-19 00:11:53.283823 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-19 00:11:53.311638 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.0 MB/s eta 0:00:00 2025-12-19 00:11:53.388294 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-19 00:11:54.453823 | 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:54.462643 | controller | 2025-12-19 00:11:54.529516 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-19 00:11:54.529569 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-19 00:11:54.966370 | controller | ok: Runtime: 0:00:35.371297 2025-12-19 00:11:54.976702 | 2025-12-19 00:11:54.976834 | TASK [Update pip] 2025-12-19 00:11:55.509147 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-19 00:12:05.265183 | controller | Collecting pip 2025-12-19 00:12:17.465313 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-19 00:12:17.526538 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.7 MB/s eta 0:00:00 2025-12-19 00:12:17.599141 | controller | Installing collected packages: pip 2025-12-19 00:12:17.599420 | controller | Attempting uninstall: pip 2025-12-19 00:12:17.601730 | controller | Found existing installation: pip 22.2.2 2025-12-19 00:12:17.756455 | controller | Uninstalling pip-22.2.2: 2025-12-19 00:12:17.775435 | controller | Successfully uninstalled pip-22.2.2 2025-12-19 00:12:18.668890 | controller | Successfully installed pip-25.3 2025-12-19 00:12:19.042837 | controller | ok: Runtime: 0:00:23.578579 2025-12-19 00:12:19.052542 | 2025-12-19 00:12:19.052698 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-19 00:12:19.278547 | controller | changed 2025-12-19 00:12:19.291933 | 2025-12-19 00:12:19.292219 | TASK [Install ansible into virtualenv] 2025-12-19 00:12:19.835868 | controller | Processing ./src/github.com/ansible/ansible 2025-12-19 00:12:19.840436 | controller | Installing build dependencies: started 2025-12-19 00:12:54.426270 | controller | Installing build dependencies: finished with status 'done' 2025-12-19 00:12:54.427598 | controller | Getting requirements to build wheel: started 2025-12-19 00:12:55.236305 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-19 00:12:55.237764 | controller | Preparing metadata (pyproject.toml): started 2025-12-19 00:12:55.715084 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-19 00:12:55.717917 | 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:12:55.721121 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-19 00:12:55.892398 | controller | ERROR 2025-12-19 00:12:55.892627 | controller | { 2025-12-19 00:12:55.892666 | controller | "delta": "0:00:36.245206", 2025-12-19 00:12:55.892689 | controller | "end": "2025-12-19 00:12:55.791141", 2025-12-19 00:12:55.892707 | controller | "msg": "non-zero return code", 2025-12-19 00:12:55.892731 | controller | "rc": 1, 2025-12-19 00:12:55.892747 | controller | "start": "2025-12-19 00:12:19.545935" 2025-12-19 00:12:55.892762 | controller | } failure 2025-12-19 00:12:55.894602 | 2025-12-19 00:12:55.894660 | PLAY RECAP 2025-12-19 00:12:55.894715 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-19 00:12:55.894740 | 2025-12-19 00:12:56.021866 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-19 00:12:56.022843 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-19 00:12:56.655593 | 2025-12-19 00:12:56.655746 | PLAY [all] 2025-12-19 00:12:56.684459 | 2025-12-19 00:12:56.684614 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-19 00:12:56.971752 | controller | changed: non-zero return code 2025-12-19 00:12:56.978756 | 2025-12-19 00:12:56.985410 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-19 00:12:57.031426 | controller | skipping: Conditional result was False 2025-12-19 00:12:57.038672 | 2025-12-19 00:12:57.038745 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-19 00:12:57.092218 | 2025-12-19 00:12:57.092373 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-19 00:12:57.119438 | 2025-12-19 00:12:57.119680 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-19 00:12:57.133799 | controller | skipping: Conditional result was False 2025-12-19 00:12:57.142726 | 2025-12-19 00:12:57.142822 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-19 00:12:57.165846 | 2025-12-19 00:12:57.166028 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-19 00:12:57.210637 | controller | skipping: Conditional result was False 2025-12-19 00:12:57.218436 | 2025-12-19 00:12:57.218512 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-19 00:12:57.262857 | controller | skipping: Conditional result was False 2025-12-19 00:12:57.271010 | 2025-12-19 00:12:57.271096 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-19 00:12:57.287561 | controller | skipping: Conditional result was False 2025-12-19 00:12:57.322966 | 2025-12-19 00:12:57.323075 | PLAY RECAP 2025-12-19 00:12:57.323118 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-19 00:12:57.323137 | 2025-12-19 00:12:57.451821 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-19 00:12:57.453113 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-19 00:12:58.568136 | 2025-12-19 00:12:58.568348 | PLAY [all:!appliance*] 2025-12-19 00:12:58.594640 | 2025-12-19 00:12:58.594784 | TASK [unregister the node] 2025-12-19 00:12:59.129129 | controller | skipping: Conditional result was False 2025-12-19 00:12:59.139154 | 2025-12-19 00:12:59.139331 | TASK [include_role : fetch-output] 2025-12-19 00:12:59.170661 | controller | ok 2025-12-19 00:12:59.192565 | 2025-12-19 00:12:59.192691 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-19 00:12:59.237462 | controller | skipping: Conditional result was False 2025-12-19 00:12:59.243903 | 2025-12-19 00:12:59.243993 | TASK [fetch-output : Set log path for single node] 2025-12-19 00:12:59.274233 | controller | ok 2025-12-19 00:12:59.283264 | 2025-12-19 00:12:59.283381 | LOOP [fetch-output : Ensure local output dirs] 2025-12-19 00:12:59.739086 | controller -> localhost | ok: "/var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/logs" 2025-12-19 00:12:59.951960 | controller -> localhost | changed: "/var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/artifacts" 2025-12-19 00:13:00.245489 | controller -> localhost | changed: "/var/lib/zuul/builds/afaae89b85904051be5b37eba44bc683/work/docs" 2025-12-19 00:13:00.260451 | 2025-12-19 00:13:00.260616 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-19 00:13:00.985484 | controller | changed: 2025-12-19 00:13:00.985693 | controller | .d..t...... ./ 2025-12-19 00:13:00.985729 | controller | cd+++++++++ controller/ 2025-12-19 00:13:00.985767 | controller | changed: All items complete 2025-12-19 00:13:00.985789 | 2025-12-19 00:13:01.451465 | controller | changed: .d..t...... ./ 2025-12-19 00:13:01.987085 | controller | changed: .d..t...... ./ 2025-12-19 00:13:02.009698 | 2025-12-19 00:13:02.009867 | TASK [include_role : fetch-output-openshift] 2025-12-19 00:13:02.027294 | controller | skipping: Conditional result was False 2025-12-19 00:13:02.035500 | 2025-12-19 00:13:02.035627 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-19 00:13:02.070047 | controller | skipping: Conditional result was False 2025-12-19 00:13:02.083114 | controller | skipping: Conditional result was False 2025-12-19 00:13:02.119347 | 2025-12-19 00:13:02.119471 | PLAY [localhost] 2025-12-19 00:13:02.133447 | 2025-12-19 00:13:02.133565 | TASK [Run Zuul manifest role] 2025-12-19 00:13:02.152671 | localhost | ok 2025-12-19 00:13:02.172216 | 2025-12-19 00:13:02.172354 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-19 00:13:02.703469 | localhost | changed 2025-12-19 00:13:02.708270 | 2025-12-19 00:13:02.708336 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-19 00:13:02.738470 | localhost | ok 2025-12-19 00:13:02.748153 | 2025-12-19 00:13:02.748247 | TASK [Set zuul-log-path fact] 2025-12-19 00:13:02.771228 | localhost | ok 2025-12-19 00:13:02.789003 | 2025-12-19 00:13:02.789135 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-19 00:13:02.819499 | localhost | ok 2025-12-19 00:13:02.833284 | 2025-12-19 00:13:02.833423 | LOOP [Run upload-logs-swift role] 2025-12-19 00:13:02.869556 | localhost | Output suppressed because no_log was given 2025-12-19 00:13:02.900178 | 2025-12-19 00:13:02.900309 | TASK [Set zuul-log-path fact] 2025-12-19 00:13:02.925548 | localhost | skipping: Conditional result was False 2025-12-19 00:13:02.933458 | 2025-12-19 00:13:02.933583 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-19 00:13:03.412743 | localhost -> localhost | ok: Runtime: 0:00:00.006076 2025-12-19 00:13:03.453322 | 2025-12-19 00:13:03.453451 | TASK [upload-logs-swift : Upload logs to swift]