2026-02-03 00:18:21.175738 | Job console starting... 2026-02-03 00:18:21.186419 | Updating repositories 2026-02-03 00:18:21.402410 | Preparing job workspace 2026-02-03 00:18:25.709695 | Running Ansible setup... 2026-02-03 00:18:30.643228 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-03 00:18:31.239589 | 2026-02-03 00:18:31.239716 | PLAY [localhost] 2026-02-03 00:18:31.249465 | 2026-02-03 00:18:31.249556 | TASK [Gathering Facts] 2026-02-03 00:18:32.285474 | localhost | ok 2026-02-03 00:18:32.311272 | 2026-02-03 00:18:32.311479 | TASK [Setup log path fact] 2026-02-03 00:18:32.331860 | localhost | ok 2026-02-03 00:18:32.352594 | 2026-02-03 00:18:32.352731 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 00:18:32.381394 | localhost | ok 2026-02-03 00:18:32.389951 | 2026-02-03 00:18:32.390067 | TASK [emit-job-header : Print job information] 2026-02-03 00:18:32.419100 | # Job Information 2026-02-03 00:18:32.419264 | Ansible Version: 2.15.12 2026-02-03 00:18:32.419296 | Job: ansible-test-sanity-docker-milestone 2026-02-03 00:18:32.419318 | Pipeline: periodic 2026-02-03 00:18:32.419338 | Executor: ze01.softwarefactory-project.io 2026-02-03 00:18:32.419356 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-03 00:18:32.419377 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b28/ansible/b28623e775444cf49dadc523bee0d45c/ 2026-02-03 00:18:32.419397 | Event ID: bc917e7b12a94a929f4345acdd6e8cbb 2026-02-03 00:18:32.423791 | 2026-02-03 00:18:32.423872 | LOOP [emit-job-header : Print node information] 2026-02-03 00:18:32.539317 | localhost | ok: 2026-02-03 00:18:32.539623 | localhost | # Node Information 2026-02-03 00:18:32.539671 | localhost | Inventory Hostname: controller 2026-02-03 00:18:32.539702 | localhost | Hostname: np0005606100 2026-02-03 00:18:32.539730 | localhost | Username: zuul 2026-02-03 00:18:32.539762 | localhost | Distro: Fedora 37 2026-02-03 00:18:32.539789 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-03 00:18:32.539815 | localhost | Region: ca-ymq-1 2026-02-03 00:18:32.539839 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-03 00:18:32.539864 | localhost | Product Name: OpenStack Nova 2026-02-03 00:18:32.539889 | localhost | Interface IP: 162.253.55.74 2026-02-03 00:18:32.569258 | 2026-02-03 00:18:32.569451 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-03 00:18:32.963879 | localhost -> localhost | changed 2026-02-03 00:18:32.977007 | 2026-02-03 00:18:32.977333 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-03 00:18:33.842574 | localhost -> localhost | changed 2026-02-03 00:18:33.869254 | 2026-02-03 00:18:33.869339 | PLAY [all:!appliance*] 2026-02-03 00:18:33.887369 | 2026-02-03 00:18:33.887449 | TASK [include_role : start-zuul-console] 2026-02-03 00:18:33.906732 | controller | ok 2026-02-03 00:18:33.922890 | 2026-02-03 00:18:33.923025 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-03 00:18:34.323773 | controller | ok 2026-02-03 00:18:34.340251 | 2026-02-03 00:18:34.340381 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-03 00:18:35.513008 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-03 00:18:35.520932 | 2026-02-03 00:18:35.521006 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-03 00:18:36.056150 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.071249 | 2026-02-03 00:18:36.071804 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-03 00:18:36.099843 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.109208 | 2026-02-03 00:18:36.109361 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-03 00:18:36.135239 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.143849 | 2026-02-03 00:18:36.143979 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-03 00:18:36.159913 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.167873 | 2026-02-03 00:18:36.167979 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-03 00:18:36.183369 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.193040 | 2026-02-03 00:18:36.193170 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-03 00:18:36.218544 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.238004 | 2026-02-03 00:18:36.238169 | TASK [Disable Fedora Modular] 2026-02-03 00:18:36.477402 | controller | changed 2026-02-03 00:18:36.487261 | 2026-02-03 00:18:36.487416 | TASK [Enable EPEL] 2026-02-03 00:18:36.513047 | controller | skipping: Conditional result was False 2026-02-03 00:18:36.520770 | 2026-02-03 00:18:36.520875 | TASK [Register the RHEL node] 2026-02-03 00:18:37.076945 | 2026-02-03 00:18:37.077392 | TASK [Show the subscription-manager status] 2026-02-03 00:18:37.671185 | controller | skipping: Conditional result was False 2026-02-03 00:18:37.679841 | 2026-02-03 00:18:37.679946 | TASK [Enable EPEL on RHEL] 2026-02-03 00:18:38.216592 | controller | skipping: Conditional result was False 2026-02-03 00:18:38.227860 | 2026-02-03 00:18:38.228073 | TASK [Install git and tox] 2026-02-03 00:19:56.924526 | controller | changed 2026-02-03 00:19:56.939418 | 2026-02-03 00:19:56.939584 | TASK [include_role : prepare-workspace] 2026-02-03 00:19:56.976620 | controller | ok 2026-02-03 00:19:57.014367 | 2026-02-03 00:19:57.014529 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-03 00:19:57.239831 | controller | ok 2026-02-03 00:19:57.246450 | 2026-02-03 00:19:57.246544 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-03 00:20:11.458923 | controller | Output suppressed because no_log was given 2026-02-03 00:20:11.483216 | 2026-02-03 00:20:11.483391 | TASK [include_role : prepare-workspace-openshift] 2026-02-03 00:20:11.504594 | controller | skipping: Conditional result was False 2026-02-03 00:20:11.544403 | 2026-02-03 00:20:11.544510 | PLAY [all:!appliance] 2026-02-03 00:20:11.573289 | 2026-02-03 00:20:11.573444 | TASK [Run add-build-sshkey role (RSA)] 2026-02-03 00:20:11.600342 | controller | ok 2026-02-03 00:20:11.628914 | 2026-02-03 00:20:11.629093 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-03 00:20:11.890183 | controller -> localhost | ok 2026-02-03 00:20:11.899103 | 2026-02-03 00:20:11.899218 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-03 00:20:11.923767 | controller | ok 2026-02-03 00:20:11.944164 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-03 00:20:11.952802 | 2026-02-03 00:20:11.952922 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-03 00:20:12.519803 | controller -> localhost | Generating public/private rsa key pair. 2026-02-03 00:20:12.520171 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_rsa. 2026-02-03 00:20:12.520217 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_rsa.pub. 2026-02-03 00:20:12.520250 | controller -> localhost | The key fingerprint is: 2026-02-03 00:20:12.520279 | controller -> localhost | SHA256:tT1IcXISlCxifCs7gB6xKGmachqNJ7ZD9V4MEq04u1Y zuul-build-sshkey 2026-02-03 00:20:12.520308 | controller -> localhost | The key's randomart image is: 2026-02-03 00:20:12.520337 | controller -> localhost | +---[RSA 2048]----+ 2026-02-03 00:20:12.520365 | controller -> localhost | | .. o*oo | 2026-02-03 00:20:12.520394 | controller -> localhost | | .. .+ o o* | 2026-02-03 00:20:12.520422 | controller -> localhost | | o.+o. o oo | 2026-02-03 00:20:12.520449 | controller -> localhost | |++++... .o + | 2026-02-03 00:20:12.520476 | controller -> localhost | |+=+.o.ooS o o | 2026-02-03 00:20:12.520515 | controller -> localhost | |B+=E .oo . | 2026-02-03 00:20:12.520557 | controller -> localhost | |+*+ . .. | 2026-02-03 00:20:12.520589 | controller -> localhost | |.= . | 2026-02-03 00:20:12.520618 | controller -> localhost | |. . | 2026-02-03 00:20:12.520648 | controller -> localhost | +----[SHA256]-----+ 2026-02-03 00:20:12.520718 | controller -> localhost | ok: Runtime: 0:00:00.102588 2026-02-03 00:20:12.536948 | 2026-02-03 00:20:12.537113 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-03 00:20:12.570274 | controller | ok 2026-02-03 00:20:12.583846 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-03 00:20:12.598515 | 2026-02-03 00:20:12.598652 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-03 00:20:12.625740 | controller | skipping: Conditional result was False 2026-02-03 00:20:12.633170 | 2026-02-03 00:20:12.633283 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-03 00:20:13.067338 | controller | changed 2026-02-03 00:20:13.083778 | 2026-02-03 00:20:13.083930 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-03 00:20:13.306062 | controller | ok 2026-02-03 00:20:13.318797 | 2026-02-03 00:20:13.318917 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-03 00:20:13.947465 | controller | changed 2026-02-03 00:20:13.955194 | 2026-02-03 00:20:13.955303 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-03 00:20:14.633598 | controller | changed 2026-02-03 00:20:14.650796 | 2026-02-03 00:20:14.651230 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-03 00:20:14.679950 | controller | skipping: Conditional result was False 2026-02-03 00:20:14.699846 | 2026-02-03 00:20:14.700179 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-03 00:20:15.188361 | controller -> localhost | changed 2026-02-03 00:20:15.208356 | 2026-02-03 00:20:15.208534 | TASK [add-build-sshkey : Add back temp key] 2026-02-03 00:20:15.511982 | controller -> localhost | Identity added: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_rsa (zuul-build-sshkey) 2026-02-03 00:20:15.512291 | controller -> localhost | ok: Runtime: 0:00:00.010055 2026-02-03 00:20:15.526603 | 2026-02-03 00:20:15.526749 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-03 00:20:15.887613 | controller | ok 2026-02-03 00:20:15.895240 | 2026-02-03 00:20:15.895339 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-03 00:20:15.931849 | controller | skipping: Conditional result was False 2026-02-03 00:20:15.948117 | 2026-02-03 00:20:15.948250 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-03 00:20:15.981969 | controller | ok 2026-02-03 00:20:16.004231 | 2026-02-03 00:20:16.004386 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-03 00:20:16.259328 | controller -> localhost | ok 2026-02-03 00:20:16.268343 | 2026-02-03 00:20:16.268490 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-03 00:20:16.299193 | controller | ok 2026-02-03 00:20:16.310554 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-03 00:20:16.317069 | 2026-02-03 00:20:16.317138 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-03 00:20:16.627566 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-03 00:20:16.627818 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_ecdsa. 2026-02-03 00:20:16.627852 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_ecdsa.pub. 2026-02-03 00:20:16.627886 | controller -> localhost | The key fingerprint is: 2026-02-03 00:20:16.627911 | controller -> localhost | SHA256:Wq3g/szr0NcNB/QI/FCZvazrXjT7FHbs03FYvfyCP6s zuul-build-sshkey 2026-02-03 00:20:16.627934 | controller -> localhost | The key's randomart image is: 2026-02-03 00:20:16.627957 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-03 00:20:16.627978 | controller -> localhost | | ...o+ | 2026-02-03 00:20:16.628000 | controller -> localhost | | oooo. .| 2026-02-03 00:20:16.628089 | controller -> localhost | | oo...o| 2026-02-03 00:20:16.628118 | controller -> localhost | | . ..++.| 2026-02-03 00:20:16.628140 | controller -> localhost | | . S . ..=*+| 2026-02-03 00:20:16.628162 | controller -> localhost | | . = . ..*.+B| 2026-02-03 00:20:16.628183 | controller -> localhost | | + o . o.=.=| 2026-02-03 00:20:16.628204 | controller -> localhost | | . + . .o.+.| 2026-02-03 00:20:16.628224 | controller -> localhost | | .o*. oE.oo.| 2026-02-03 00:20:16.628245 | controller -> localhost | +----[SHA256]-----+ 2026-02-03 00:20:16.628306 | controller -> localhost | ok: Runtime: 0:00:00.009807 2026-02-03 00:20:16.636449 | 2026-02-03 00:20:16.636550 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-03 00:20:16.673172 | controller | ok 2026-02-03 00:20:16.688513 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-03 00:20:16.702494 | 2026-02-03 00:20:16.702637 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-03 00:20:16.728318 | controller | skipping: Conditional result was False 2026-02-03 00:20:16.735402 | 2026-02-03 00:20:16.735521 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-03 00:20:17.043558 | controller | changed 2026-02-03 00:20:17.053439 | 2026-02-03 00:20:17.053563 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-03 00:20:17.290668 | controller | ok 2026-02-03 00:20:17.297286 | 2026-02-03 00:20:17.297796 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-03 00:20:17.958227 | controller | changed 2026-02-03 00:20:17.970254 | 2026-02-03 00:20:17.970419 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-03 00:20:18.695479 | controller | changed 2026-02-03 00:20:18.704354 | 2026-02-03 00:20:18.704460 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-03 00:20:18.730358 | controller | skipping: Conditional result was False 2026-02-03 00:20:18.741747 | 2026-02-03 00:20:18.741882 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-03 00:20:19.023323 | controller -> localhost | changed 2026-02-03 00:20:19.050398 | 2026-02-03 00:20:19.050597 | TASK [add-build-sshkey : Add back temp key] 2026-02-03 00:20:19.384806 | controller -> localhost | Identity added: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/b28623e775444cf49dadc523bee0d45c_id_ecdsa (zuul-build-sshkey) 2026-02-03 00:20:19.385169 | controller -> localhost | ok: Runtime: 0:00:00.009507 2026-02-03 00:20:19.398099 | 2026-02-03 00:20:19.398259 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-03 00:20:19.610416 | controller | ok 2026-02-03 00:20:19.622937 | 2026-02-03 00:20:19.623122 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-03 00:20:19.670241 | controller | skipping: Conditional result was False 2026-02-03 00:20:19.697504 | 2026-02-03 00:20:19.697688 | TASK [include_role : remove-zuul-sshkey] 2026-02-03 00:20:19.725084 | controller | skipping: Conditional result was False 2026-02-03 00:20:19.739244 | 2026-02-03 00:20:19.739409 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-03 00:20:19.990512 | controller | ok: "logs" 2026-02-03 00:20:19.990875 | controller | ok: All items complete 2026-02-03 00:20:19.990921 | 2026-02-03 00:20:20.182922 | controller | ok: "artifacts" 2026-02-03 00:20:20.364688 | controller | ok: "docs" 2026-02-03 00:20:20.376514 | 2026-02-03 00:20:20.376683 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-03 00:20:20.615123 | controller | changed: "logs" 2026-02-03 00:20:20.813258 | controller | changed: "artifacts" 2026-02-03 00:20:21.007212 | controller | changed: "docs" 2026-02-03 00:20:21.056940 | 2026-02-03 00:20:21.057147 | PLAY RECAP 2026-02-03 00:20:21.057247 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-03 00:20:21.057361 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-03 00:20:21.057408 | 2026-02-03 00:20:21.206766 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-03 00:20:21.207924 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 00:20:21.867682 | 2026-02-03 00:20:21.867810 | PLAY [all] 2026-02-03 00:20:21.892132 | 2026-02-03 00:20:21.892292 | TASK [Install binary dependencies] 2026-02-03 00:20:21.943980 | controller | ok 2026-02-03 00:20:21.966250 | 2026-02-03 00:20:21.966405 | TASK [bindep : Include find tasks] 2026-02-03 00:20:21.996659 | controller | ok 2026-02-03 00:20:22.004700 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-03 00:20:22.011140 | 2026-02-03 00:20:22.011226 | TASK [bindep : Look for bindep.txt] 2026-02-03 00:25:22.171105 | controller | ok 2026-02-03 00:25:22.182449 | 2026-02-03 00:25:22.182584 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:25:22.209167 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.221467 | 2026-02-03 00:25:22.221667 | TASK [bindep : Look for other-requirements.txt] 2026-02-03 00:25:22.465134 | controller | ok 2026-02-03 00:25:22.477245 | 2026-02-03 00:25:22.477388 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:25:22.514102 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.523993 | 2026-02-03 00:25:22.524146 | TASK [bindep : Look for bindep fallback file] 2026-02-03 00:25:22.580211 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.590406 | 2026-02-03 00:25:22.590572 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:25:22.628092 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.638082 | 2026-02-03 00:25:22.638247 | TASK [bindep : Include bindep tasks] 2026-02-03 00:25:22.682336 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.692133 | 2026-02-03 00:25:22.692284 | TASK [bindep : Include install tasks] 2026-02-03 00:25:22.719395 | controller | skipping: Conditional result was False 2026-02-03 00:25:22.733967 | 2026-02-03 00:25:22.734185 | LOOP [bindep : Include package tasks] 2026-02-03 00:25:22.817192 | 2026-02-03 00:25:22.817789 | TASK [Run test-setup role] 2026-02-03 00:25:22.844411 | controller | ok 2026-02-03 00:25:22.872527 | 2026-02-03 00:25:22.872675 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-03 00:25:23.112585 | controller | ok 2026-02-03 00:25:23.119889 | 2026-02-03 00:25:23.119977 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-03 00:25:23.659438 | controller | skipping: Conditional result was False 2026-02-03 00:25:23.694809 | 2026-02-03 00:25:23.694919 | PLAY RECAP 2026-02-03 00:25:23.694973 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-03 00:25:23.695001 | 2026-02-03 00:25:23.805912 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 00:25:23.806856 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-03 00:25:24.456116 | 2026-02-03 00:25:24.456255 | PLAY [controller] 2026-02-03 00:25:24.478674 | 2026-02-03 00:25:24.478802 | TASK [Create the /root directory] 2026-02-03 00:25:25.065698 | controller | ok 2026-02-03 00:25:25.083398 | 2026-02-03 00:25:25.085237 | TASK [Install glibc-langpack-en] 2026-02-03 00:25:29.039956 | controller | ok: Nothing to do 2026-02-03 00:25:29.057867 | 2026-02-03 00:25:29.058116 | TASK [Ensure controller directory exists] 2026-02-03 00:25:29.300373 | controller | changed 2026-02-03 00:25:29.315973 | 2026-02-03 00:25:29.316229 | TASK [Install container runtime] 2026-02-03 00:25:29.367512 | controller | ok 2026-02-03 00:25:29.429075 | 2026-02-03 00:25:29.429236 | LOOP [ensure-podman : Find distribution installation] 2026-02-03 00:25:29.456920 | controller | ok: "/var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-03 00:25:29.473621 | controller | included: /var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-03 00:25:29.483363 | 2026-02-03 00:25:29.483508 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-03 00:26:32.150374 | controller | changed 2026-02-03 00:26:32.161929 | 2026-02-03 00:26:32.162103 | TASK [ensure-podman : Fetch podman version] 2026-02-03 00:26:32.730157 | controller | Client: Podman Engine 2026-02-03 00:26:32.766744 | controller | Version: 4.6.2 2026-02-03 00:26:32.766805 | controller | API Version: 4.6.2 2026-02-03 00:26:32.766897 | controller | Go Version: go1.19.12 2026-02-03 00:26:32.766922 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-03 00:26:32.766930 | controller | OS/Arch: linux/amd64 2026-02-03 00:26:33.208959 | controller | ok: Runtime: 0:00:00.220847 2026-02-03 00:26:33.215319 | 2026-02-03 00:26:33.215397 | TASK [ensure-podman : Print podman version installed] 2026-02-03 00:26:33.255700 | Podman version: Client: Podman Engine 2026-02-03 00:26:33.255852 | Version: 4.6.2 2026-02-03 00:26:33.255880 | API Version: 4.6.2 2026-02-03 00:26:33.255900 | Go Version: go1.19.12 2026-02-03 00:26:33.255918 | Built: Mon Aug 28 19:38:31 2023 2026-02-03 00:26:33.255936 | OS/Arch: linux/amd64 2026-02-03 00:26:33.261703 | 2026-02-03 00:26:33.261765 | TASK [ensure-podman : Validate podman engine] 2026-02-03 00:26:33.792628 | controller | skipping: Conditional result was False 2026-02-03 00:26:33.809129 | 2026-02-03 00:26:33.809534 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-03 00:26:33.827414 | controller | skipping: Conditional result was False 2026-02-03 00:26:33.854318 | 2026-02-03 00:26:33.854505 | TASK [Ensure python3.8 is present] 2026-02-03 00:26:33.881505 | controller | skipping: Conditional result was False 2026-02-03 00:26:33.897237 | 2026-02-03 00:26:33.897411 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-03 00:26:33.927687 | controller | ok 2026-02-03 00:26:33.958056 | 2026-02-03 00:26:33.958219 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-03 00:26:35.549511 | controller | ok: Nothing to do 2026-02-03 00:26:35.562884 | 2026-02-03 00:26:35.563057 | TASK [our-ensure-python : Also install python3-devel] 2026-02-03 00:26:44.756211 | controller | changed 2026-02-03 00:26:44.781318 | 2026-02-03 00:26:44.781467 | TASK [Run ensure-virtualenv role] 2026-02-03 00:26:44.808167 | controller | ok 2026-02-03 00:26:44.836894 | 2026-02-03 00:26:44.837046 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-03 00:26:45.082533 | controller | /usr/bin/virtualenv 2026-02-03 00:26:45.402003 | controller | ok: Runtime: 0:00:00.003357 2026-02-03 00:26:45.408249 | 2026-02-03 00:26:45.408320 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-03 00:26:45.427755 | controller | skipping: Conditional result was False 2026-02-03 00:26:45.428036 | controller | ok: All items complete 2026-02-03 00:26:45.428083 | 2026-02-03 00:26:45.456961 | 2026-02-03 00:26:45.457171 | TASK [Find the full path of the Python interpreter] 2026-02-03 00:26:45.676810 | controller | /usr/bin/python3 2026-02-03 00:26:46.001831 | controller | ok 2026-02-03 00:26:46.017445 | 2026-02-03 00:26:46.017630 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-03 00:26:47.067141 | controller | created virtual environment CPython3.11.0.final.0-64 in 572ms 2026-02-03 00:26:47.082037 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-03 00:26:47.082063 | 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) 2026-02-03 00:26:47.082073 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-03 00:26:47.082087 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-03 00:26:47.572259 | controller | changed 2026-02-03 00:26:47.581997 | 2026-02-03 00:26:47.582174 | TASK [Set selinux package] 2026-02-03 00:26:47.614361 | controller | ok 2026-02-03 00:26:47.619582 | 2026-02-03 00:26:47.619663 | TASK [Set selinux package (Fedora)] 2026-02-03 00:26:47.669464 | controller | ok 2026-02-03 00:26:47.675529 | 2026-02-03 00:26:47.675604 | TASK [Install selinux into virtualenv] 2026-02-03 00:26:48.937854 | controller | Collecting selinux-please-lie-to-me 2026-02-03 00:26:48.978650 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-03 00:26:49.289801 | controller | Collecting setuptools<50.0.0 2026-02-03 00:26:49.294473 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-03 00:26:49.330609 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.1 MB/s eta 0:00:00 2026-02-03 00:26:49.426619 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-03 00:26:49.426847 | controller | Attempting uninstall: setuptools 2026-02-03 00:26:49.429364 | controller | Found existing installation: setuptools 62.6.0 2026-02-03 00:26:49.490298 | controller | Uninstalling setuptools-62.6.0: 2026-02-03 00:26:49.498240 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-03 00:26:49.856857 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-03 00:26:49.980037 | controller | 2026-02-03 00:26:50.077504 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-03 00:26:50.077555 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-03 00:26:50.211402 | controller | ok: Runtime: 0:00:02.203687 2026-02-03 00:26:50.218998 | 2026-02-03 00:26:50.219144 | TASK [Install pytest-forked into virtualenv] 2026-02-03 00:26:50.794446 | controller | Collecting pytest-forked 2026-02-03 00:26:50.837679 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-03 00:26:50.884986 | controller | Collecting py 2026-02-03 00:26:50.889331 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-03 00:26:50.909619 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00 2026-02-03 00:26:51.012423 | controller | Collecting pytest>=3.10 2026-02-03 00:26:51.015626 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-03 00:26:51.029509 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 32.9 MB/s eta 0:00:00 2026-02-03 00:26:51.069574 | controller | Collecting iniconfig>=1.0.1 2026-02-03 00:26:51.073487 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-03 00:26:51.124280 | controller | Collecting packaging>=22 2026-02-03 00:26:51.133355 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-03 00:26:51.142824 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 9.6 MB/s eta 0:00:00 2026-02-03 00:26:51.172912 | controller | Collecting pluggy<2,>=1.5 2026-02-03 00:26:51.177025 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-03 00:26:51.223741 | controller | Collecting pygments>=2.7.2 2026-02-03 00:26:51.230262 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-03 00:26:51.249644 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 75.8 MB/s eta 0:00:00 2026-02-03 00:26:51.319527 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-03 00:26:52.438872 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-03 00:26:52.447571 | controller | 2026-02-03 00:26:52.525783 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-03 00:26:52.525831 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-03 00:26:52.771785 | controller | ok: Runtime: 0:00:02.105014 2026-02-03 00:26:52.778822 | 2026-02-03 00:26:52.778934 | TASK [Update pip] 2026-02-03 00:26:53.281810 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-03 00:26:53.422141 | controller | Collecting pip 2026-02-03 00:26:53.457357 | controller | Downloading pip-26.0-py3-none-any.whl (1.8 MB) 2026-02-03 00:26:53.506069 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.4 MB/s eta 0:00:00 2026-02-03 00:26:53.569087 | controller | Installing collected packages: pip 2026-02-03 00:26:53.569301 | controller | Attempting uninstall: pip 2026-02-03 00:26:53.571461 | controller | Found existing installation: pip 22.2.2 2026-02-03 00:26:53.707473 | controller | Uninstalling pip-22.2.2: 2026-02-03 00:26:53.731723 | controller | Successfully uninstalled pip-22.2.2 2026-02-03 00:26:54.645443 | controller | Successfully installed pip-26.0 2026-02-03 00:26:54.827540 | controller | ok: Runtime: 0:00:01.734545 2026-02-03 00:26:54.834635 | 2026-02-03 00:26:54.834906 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-03 00:26:55.053456 | controller | changed 2026-02-03 00:26:55.062475 | 2026-02-03 00:26:55.062605 | TASK [Install ansible into virtualenv] 2026-02-03 00:26:55.560479 | controller | Processing ./src/github.com/ansible/ansible 2026-02-03 00:26:55.563077 | controller | Installing build dependencies: started 2026-02-03 00:26:56.488914 | controller | Installing build dependencies: finished with status 'done' 2026-02-03 00:26:57.242209 | controller | Getting requirements to build wheel: started 2026-02-03 00:26:57.242253 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-03 00:26:57.697390 | controller | Preparing metadata (pyproject.toml): started 2026-02-03 00:26:57.697428 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-03 00:26:57.698843 | 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. 2026-02-03 00:26:57.698860 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-03 00:26:58.112828 | controller | ERROR 2026-02-03 00:26:58.113253 | controller | { 2026-02-03 00:26:58.113299 | controller | "delta": "0:00:02.489074", 2026-02-03 00:26:58.113327 | controller | "end": "2026-02-03 00:26:57.761894", 2026-02-03 00:26:58.113350 | controller | "msg": "non-zero return code", 2026-02-03 00:26:58.113398 | controller | "rc": 1, 2026-02-03 00:26:58.113422 | controller | "start": "2026-02-03 00:26:55.272820" 2026-02-03 00:26:58.113442 | controller | } failure 2026-02-03 00:26:58.115994 | 2026-02-03 00:26:58.116087 | PLAY RECAP 2026-02-03 00:26:58.116152 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-03 00:26:58.116181 | 2026-02-03 00:26:58.359901 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-03 00:26:58.361748 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 00:26:58.985863 | 2026-02-03 00:26:58.986002 | PLAY [all] 2026-02-03 00:26:59.009790 | 2026-02-03 00:26:59.009947 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-03 00:26:59.390434 | controller | changed: non-zero return code 2026-02-03 00:26:59.401634 | 2026-02-03 00:26:59.401739 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-03 00:26:59.417785 | controller | skipping: Conditional result was False 2026-02-03 00:26:59.429123 | 2026-02-03 00:26:59.429238 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-03 00:26:59.455459 | 2026-02-03 00:26:59.455770 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-03 00:26:59.490472 | 2026-02-03 00:26:59.490657 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-03 00:26:59.505704 | controller | skipping: Conditional result was False 2026-02-03 00:26:59.517959 | 2026-02-03 00:26:59.518255 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-03 00:26:59.557918 | 2026-02-03 00:26:59.558151 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-03 00:26:59.572726 | controller | skipping: Conditional result was False 2026-02-03 00:26:59.582353 | 2026-02-03 00:26:59.582436 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-03 00:26:59.597414 | controller | skipping: Conditional result was False 2026-02-03 00:26:59.606642 | 2026-02-03 00:26:59.606774 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-03 00:26:59.622055 | controller | skipping: Conditional result was False 2026-02-03 00:26:59.654621 | 2026-02-03 00:26:59.654744 | PLAY RECAP 2026-02-03 00:26:59.654789 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-03 00:26:59.654810 | 2026-02-03 00:26:59.771654 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 00:26:59.772820 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-03 00:27:00.427179 | 2026-02-03 00:27:00.427324 | PLAY [all:!appliance*] 2026-02-03 00:27:00.457806 | 2026-02-03 00:27:00.457951 | TASK [unregister the node] 2026-02-03 00:27:01.004881 | controller | skipping: Conditional result was False 2026-02-03 00:27:01.014054 | 2026-02-03 00:27:01.014284 | TASK [include_role : fetch-output] 2026-02-03 00:27:01.055860 | controller | ok 2026-02-03 00:27:01.077425 | 2026-02-03 00:27:01.077550 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-03 00:27:01.141125 | controller | skipping: Conditional result was False 2026-02-03 00:27:01.148666 | 2026-02-03 00:27:01.148758 | TASK [fetch-output : Set log path for single node] 2026-02-03 00:27:01.184295 | controller | ok 2026-02-03 00:27:01.193263 | 2026-02-03 00:27:01.193419 | LOOP [fetch-output : Ensure local output dirs] 2026-02-03 00:27:01.611684 | controller -> localhost | ok: "/var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/logs" 2026-02-03 00:27:01.842538 | controller -> localhost | changed: "/var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/artifacts" 2026-02-03 00:27:02.102266 | controller -> localhost | changed: "/var/lib/zuul/builds/b28623e775444cf49dadc523bee0d45c/work/docs" 2026-02-03 00:27:02.120674 | 2026-02-03 00:27:02.120801 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-03 00:27:02.888230 | controller | changed: 2026-02-03 00:27:02.888481 | controller | .d..t...... ./ 2026-02-03 00:27:02.888514 | controller | cd+++++++++ controller/ 2026-02-03 00:27:02.888549 | controller | changed: All items complete 2026-02-03 00:27:02.888570 | 2026-02-03 00:27:03.356105 | controller | changed: .d..t...... ./ 2026-02-03 00:27:03.863154 | controller | changed: .d..t...... ./ 2026-02-03 00:27:03.888248 | 2026-02-03 00:27:03.888388 | TASK [include_role : fetch-output-openshift] 2026-02-03 00:27:03.914610 | controller | skipping: Conditional result was False 2026-02-03 00:27:03.924198 | 2026-02-03 00:27:03.924318 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-03 00:27:03.968101 | controller | skipping: Conditional result was False 2026-02-03 00:27:03.981779 | controller | skipping: Conditional result was False 2026-02-03 00:27:04.033828 | 2026-02-03 00:27:04.033955 | PLAY [localhost] 2026-02-03 00:27:04.054372 | 2026-02-03 00:27:04.054536 | TASK [Run Zuul manifest role] 2026-02-03 00:27:04.074195 | localhost | ok 2026-02-03 00:27:04.089345 | 2026-02-03 00:27:04.089463 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-03 00:27:04.485659 | localhost | changed 2026-02-03 00:27:04.490667 | 2026-02-03 00:27:04.490744 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-03 00:27:04.525555 | localhost | ok 2026-02-03 00:27:04.533786 | 2026-02-03 00:27:04.533886 | TASK [Set zuul-log-path fact] 2026-02-03 00:27:04.553314 | localhost | ok 2026-02-03 00:27:04.568993 | 2026-02-03 00:27:04.569148 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 00:27:04.597907 | localhost | ok 2026-02-03 00:27:04.606507 | 2026-02-03 00:27:04.606628 | LOOP [Run upload-logs-swift role] 2026-02-03 00:27:04.642664 | localhost | Output suppressed because no_log was given 2026-02-03 00:27:04.667283 | 2026-02-03 00:27:04.667385 | TASK [Set zuul-log-path fact] 2026-02-03 00:27:04.691515 | localhost | skipping: Conditional result was False 2026-02-03 00:27:04.699276 | 2026-02-03 00:27:04.699412 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-03 00:27:05.138899 | localhost -> localhost | ok: Runtime: 0:00:00.005688 2026-02-03 00:27:05.178772 | 2026-02-03 00:27:05.179150 | TASK [upload-logs-swift : Upload logs to swift]