2025-11-19 00:06:42.279594 | Job console starting... 2025-11-19 00:06:42.288508 | Updating repositories 2025-11-19 00:06:42.413694 | Preparing job workspace 2025-11-19 00:06:47.900806 | Running Ansible setup... 2025-11-19 00:06:52.766920 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-19 00:06:53.378781 | 2025-11-19 00:06:53.378929 | PLAY [localhost] 2025-11-19 00:06:53.387542 | 2025-11-19 00:06:53.387618 | TASK [Gathering Facts] 2025-11-19 00:06:54.454503 | localhost | ok 2025-11-19 00:06:54.475392 | 2025-11-19 00:06:54.475540 | TASK [Setup log path fact] 2025-11-19 00:06:54.501096 | localhost | ok 2025-11-19 00:06:54.523883 | 2025-11-19 00:06:54.524031 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-19 00:06:54.557614 | localhost | ok 2025-11-19 00:06:54.574949 | 2025-11-19 00:06:54.575099 | TASK [emit-job-header : Print job information] 2025-11-19 00:06:54.622415 | # Job Information 2025-11-19 00:06:54.622831 | Ansible Version: 2.15.12 2025-11-19 00:06:54.622908 | Job: ansible-test-sanity-docker-milestone 2025-11-19 00:06:54.622955 | Pipeline: periodic 2025-11-19 00:06:54.622996 | Executor: ze02.softwarefactory-project.io 2025-11-19 00:06:54.623036 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-19 00:06:54.623082 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/ed7/ansible/ed744bfaf5da4a2696e0133f79bc9c80/ 2025-11-19 00:06:54.623124 | Event ID: 500c7b88eb4e448ea8cf6a57d3831197 2025-11-19 00:06:54.632174 | 2025-11-19 00:06:54.632326 | LOOP [emit-job-header : Print node information] 2025-11-19 00:06:54.740358 | localhost | ok: 2025-11-19 00:06:54.740618 | localhost | # Node Information 2025-11-19 00:06:54.740659 | localhost | Inventory Hostname: controller 2025-11-19 00:06:54.740716 | localhost | Hostname: np0005527400 2025-11-19 00:06:54.740933 | localhost | Username: zuul 2025-11-19 00:06:54.740968 | localhost | Distro: Fedora 37 2025-11-19 00:06:54.740993 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-11-19 00:06:54.741017 | localhost | Region: ca-ymq-1 2025-11-19 00:06:54.741040 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-19 00:06:54.741064 | localhost | Product Name: OpenStack Nova 2025-11-19 00:06:54.741087 | localhost | Interface IP: 162.253.55.49 2025-11-19 00:06:54.753560 | 2025-11-19 00:06:54.753720 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-19 00:06:55.174110 | localhost -> localhost | changed 2025-11-19 00:06:55.180995 | 2025-11-19 00:06:55.181075 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-19 00:06:56.185071 | localhost -> localhost | changed 2025-11-19 00:06:56.208904 | 2025-11-19 00:06:56.209027 | PLAY [all:!appliance*] 2025-11-19 00:06:56.232095 | 2025-11-19 00:06:56.232343 | TASK [include_role : start-zuul-console] 2025-11-19 00:06:56.254229 | controller | ok 2025-11-19 00:06:56.269768 | 2025-11-19 00:06:56.269877 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-19 00:06:56.772176 | controller | ok 2025-11-19 00:06:56.796985 | 2025-11-19 00:06:56.797137 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-19 00:07:19.430808 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-19 00:07:19.447847 | 2025-11-19 00:07:19.448021 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-19 00:07:19.998531 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.007911 | 2025-11-19 00:07:20.008009 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-19 00:07:20.032989 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.042940 | 2025-11-19 00:07:20.043039 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-19 00:07:20.077959 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.088081 | 2025-11-19 00:07:20.088181 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-19 00:07:20.124468 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.134226 | 2025-11-19 00:07:20.134324 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-19 00:07:20.171182 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.180927 | 2025-11-19 00:07:20.181026 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-19 00:07:20.207295 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.246058 | 2025-11-19 00:07:20.246230 | TASK [Disable Fedora Modular] 2025-11-19 00:07:20.634999 | controller | changed 2025-11-19 00:07:20.643299 | 2025-11-19 00:07:20.643389 | TASK [Enable EPEL] 2025-11-19 00:07:20.668030 | controller | skipping: Conditional result was False 2025-11-19 00:07:20.674902 | 2025-11-19 00:07:20.674989 | TASK [Register the RHEL node] 2025-11-19 00:07:21.235212 | 2025-11-19 00:07:21.235490 | TASK [Show the subscription-manager status] 2025-11-19 00:07:21.801601 | controller | skipping: Conditional result was False 2025-11-19 00:07:21.812014 | 2025-11-19 00:07:21.812138 | TASK [Enable EPEL on RHEL] 2025-11-19 00:07:22.368379 | controller | skipping: Conditional result was False 2025-11-19 00:07:22.390215 | 2025-11-19 00:07:22.390454 | TASK [Install git and tox] 2025-11-19 00:08:15.419550 | controller | changed 2025-11-19 00:08:15.433277 | 2025-11-19 00:08:15.433436 | TASK [include_role : prepare-workspace] 2025-11-19 00:08:15.475142 | controller | ok 2025-11-19 00:08:15.512631 | 2025-11-19 00:08:15.512788 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-19 00:08:15.844793 | controller | ok 2025-11-19 00:08:15.853899 | 2025-11-19 00:08:15.853990 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-19 00:08:28.191427 | controller | Output suppressed because no_log was given 2025-11-19 00:08:28.204115 | 2025-11-19 00:08:28.204265 | TASK [include_role : prepare-workspace-openshift] 2025-11-19 00:08:28.230915 | controller | skipping: Conditional result was False 2025-11-19 00:08:28.260421 | 2025-11-19 00:08:28.260523 | PLAY [all:!appliance] 2025-11-19 00:08:28.276739 | 2025-11-19 00:08:28.276807 | TASK [Run add-build-sshkey role (RSA)] 2025-11-19 00:08:28.308541 | controller | ok 2025-11-19 00:08:28.324659 | 2025-11-19 00:08:28.324775 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-19 00:08:28.583457 | controller -> localhost | ok 2025-11-19 00:08:28.591862 | 2025-11-19 00:08:28.591955 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-19 00:08:28.623628 | controller | ok 2025-11-19 00:08:28.649733 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-19 00:08:28.656339 | 2025-11-19 00:08:28.656405 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-19 00:08:29.192464 | controller -> localhost | Generating public/private rsa key pair. 2025-11-19 00:08:29.192782 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_rsa. 2025-11-19 00:08:29.192818 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_rsa.pub. 2025-11-19 00:08:29.192840 | controller -> localhost | The key fingerprint is: 2025-11-19 00:08:29.192862 | controller -> localhost | SHA256:AvNPTo2XecsFQOvzB6zCFVQm/gDXmPcXH2E7cbeQ9to zuul-build-sshkey 2025-11-19 00:08:29.192889 | controller -> localhost | The key's randomart image is: 2025-11-19 00:08:29.192910 | controller -> localhost | +---[RSA 2048]----+ 2025-11-19 00:08:29.192928 | controller -> localhost | | ..*=o..++| 2025-11-19 00:08:29.192948 | controller -> localhost | | =o=oooo*| 2025-11-19 00:08:29.192966 | controller -> localhost | | o =.o..++| 2025-11-19 00:08:29.192983 | controller -> localhost | | + + B ...+| 2025-11-19 00:08:29.193000 | controller -> localhost | | o S O = +. | 2025-11-19 00:08:29.193030 | controller -> localhost | | B o * = E | 2025-11-19 00:08:29.193066 | controller -> localhost | | = . + . | 2025-11-19 00:08:29.193089 | controller -> localhost | | . . | 2025-11-19 00:08:29.193108 | controller -> localhost | | | 2025-11-19 00:08:29.193132 | controller -> localhost | +----[SHA256]-----+ 2025-11-19 00:08:29.193192 | controller -> localhost | ok: Runtime: 0:00:00.059723 2025-11-19 00:08:29.201231 | 2025-11-19 00:08:29.201311 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-19 00:08:29.234315 | controller | ok 2025-11-19 00:08:29.245609 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-19 00:08:29.255268 | 2025-11-19 00:08:29.255349 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-19 00:08:29.291141 | controller | skipping: Conditional result was False 2025-11-19 00:08:29.299205 | 2025-11-19 00:08:29.299279 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-19 00:08:29.749420 | controller | changed 2025-11-19 00:08:29.761286 | 2025-11-19 00:08:29.761441 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-19 00:08:30.014507 | controller | ok 2025-11-19 00:08:30.036268 | 2025-11-19 00:08:30.036479 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-19 00:08:30.742508 | controller | changed 2025-11-19 00:08:30.752817 | 2025-11-19 00:08:30.752991 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-19 00:08:31.429529 | controller | changed 2025-11-19 00:08:31.435828 | 2025-11-19 00:08:31.435920 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-19 00:08:31.464871 | controller | skipping: Conditional result was False 2025-11-19 00:08:31.472527 | 2025-11-19 00:08:31.472621 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-19 00:08:31.835811 | controller -> localhost | changed 2025-11-19 00:08:31.867965 | 2025-11-19 00:08:31.868147 | TASK [add-build-sshkey : Add back temp key] 2025-11-19 00:08:32.185389 | controller -> localhost | Identity added: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_rsa (zuul-build-sshkey) 2025-11-19 00:08:32.185898 | controller -> localhost | ok: Runtime: 0:00:00.015791 2025-11-19 00:08:32.201407 | 2025-11-19 00:08:32.201552 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-19 00:08:32.514529 | controller | ok 2025-11-19 00:08:32.529889 | 2025-11-19 00:08:32.530204 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-19 00:08:32.577199 | controller | skipping: Conditional result was False 2025-11-19 00:08:32.602411 | 2025-11-19 00:08:32.602522 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-19 00:08:32.639268 | controller | ok 2025-11-19 00:08:32.656921 | 2025-11-19 00:08:32.657019 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-19 00:08:32.937106 | controller -> localhost | ok 2025-11-19 00:08:32.945317 | 2025-11-19 00:08:32.945411 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-19 00:08:32.978934 | controller | ok 2025-11-19 00:08:32.993537 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-19 00:08:33.000833 | 2025-11-19 00:08:33.000942 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-19 00:08:33.342910 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-19 00:08:33.343176 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_ecdsa. 2025-11-19 00:08:33.343208 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_ecdsa.pub. 2025-11-19 00:08:33.343242 | controller -> localhost | The key fingerprint is: 2025-11-19 00:08:33.343264 | controller -> localhost | SHA256:k4ZSam6uOyN3oSGxpvxF9crOdEtLbBQjL9adi3hUoI4 zuul-build-sshkey 2025-11-19 00:08:33.343287 | controller -> localhost | The key's randomart image is: 2025-11-19 00:08:33.343308 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-19 00:08:33.343328 | controller -> localhost | | . | 2025-11-19 00:08:33.343347 | controller -> localhost | | . . | 2025-11-19 00:08:33.343366 | controller -> localhost | | .+ o . | 2025-11-19 00:08:33.343384 | controller -> localhost | |. o+.=.= . | 2025-11-19 00:08:33.343402 | controller -> localhost | | o +E.+S* o | 2025-11-19 00:08:33.343421 | controller -> localhost | |o..oo.o.B.. . | 2025-11-19 00:08:33.343439 | controller -> localhost | |+. ooo = O . | 2025-11-19 00:08:33.343458 | controller -> localhost | |o.=oo + * o | 2025-11-19 00:08:33.343476 | controller -> localhost | | o+B. o o | 2025-11-19 00:08:33.343494 | controller -> localhost | +----[SHA256]-----+ 2025-11-19 00:08:33.343553 | controller -> localhost | ok: Runtime: 0:00:00.017297 2025-11-19 00:08:33.350992 | 2025-11-19 00:08:33.351061 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-19 00:08:33.393315 | controller | ok 2025-11-19 00:08:33.401370 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-19 00:08:33.411743 | 2025-11-19 00:08:33.411849 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-19 00:08:33.437641 | controller | skipping: Conditional result was False 2025-11-19 00:08:33.446848 | 2025-11-19 00:08:33.446993 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-19 00:08:33.722492 | controller | changed 2025-11-19 00:08:33.735854 | 2025-11-19 00:08:33.736033 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-19 00:08:33.992102 | controller | ok 2025-11-19 00:08:34.008588 | 2025-11-19 00:08:34.008855 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-19 00:08:34.665790 | controller | changed 2025-11-19 00:08:34.679625 | 2025-11-19 00:08:34.679816 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-19 00:08:35.343457 | controller | changed 2025-11-19 00:08:35.359832 | 2025-11-19 00:08:35.359988 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-19 00:08:35.389285 | controller | skipping: Conditional result was False 2025-11-19 00:08:35.405511 | 2025-11-19 00:08:35.405764 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-19 00:08:35.699286 | controller -> localhost | changed 2025-11-19 00:08:35.712260 | 2025-11-19 00:08:35.712782 | TASK [add-build-sshkey : Add back temp key] 2025-11-19 00:08:36.017076 | controller -> localhost | Identity added: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/ed744bfaf5da4a2696e0133f79bc9c80_id_ecdsa (zuul-build-sshkey) 2025-11-19 00:08:36.017477 | controller -> localhost | ok: Runtime: 0:00:00.008494 2025-11-19 00:08:36.025140 | 2025-11-19 00:08:36.025207 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-19 00:08:36.241256 | controller | ok 2025-11-19 00:08:36.246870 | 2025-11-19 00:08:36.246936 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-19 00:08:36.293555 | controller | skipping: Conditional result was False 2025-11-19 00:08:36.305228 | 2025-11-19 00:08:36.305293 | TASK [include_role : remove-zuul-sshkey] 2025-11-19 00:08:36.330371 | controller | skipping: Conditional result was False 2025-11-19 00:08:36.344944 | 2025-11-19 00:08:36.345034 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-19 00:08:36.610777 | controller | ok: "logs" 2025-11-19 00:08:36.611324 | controller | ok: All items complete 2025-11-19 00:08:36.611387 | 2025-11-19 00:08:36.808774 | controller | ok: "artifacts" 2025-11-19 00:08:37.023831 | controller | ok: "docs" 2025-11-19 00:08:37.040734 | 2025-11-19 00:08:37.040949 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-19 00:08:37.303001 | controller | changed: "logs" 2025-11-19 00:08:37.517928 | controller | changed: "artifacts" 2025-11-19 00:08:37.728627 | controller | changed: "docs" 2025-11-19 00:08:37.767895 | 2025-11-19 00:08:37.768045 | PLAY RECAP 2025-11-19 00:08:37.768099 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-19 00:08:37.768126 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-19 00:08:37.768144 | 2025-11-19 00:08:37.925378 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-19 00:08:37.926471 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-19 00:08:38.515753 | 2025-11-19 00:08:38.515919 | PLAY [all] 2025-11-19 00:08:38.539129 | 2025-11-19 00:08:38.539229 | TASK [Install binary dependencies] 2025-11-19 00:08:38.589784 | controller | ok 2025-11-19 00:08:38.610473 | 2025-11-19 00:08:38.610583 | TASK [bindep : Include find tasks] 2025-11-19 00:08:38.653155 | controller | ok 2025-11-19 00:08:38.661943 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-19 00:08:38.668375 | 2025-11-19 00:08:38.668465 | TASK [bindep : Look for bindep.txt] 2025-11-19 00:08:39.040738 | controller | ok 2025-11-19 00:08:39.050920 | 2025-11-19 00:08:39.051136 | TASK [bindep : Define bindep_file fact] 2025-11-19 00:08:39.079109 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.086570 | 2025-11-19 00:08:39.086739 | TASK [bindep : Look for other-requirements.txt] 2025-11-19 00:08:39.306529 | controller | ok 2025-11-19 00:08:39.315190 | 2025-11-19 00:08:39.315372 | TASK [bindep : Define bindep_file fact] 2025-11-19 00:08:39.352942 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.362604 | 2025-11-19 00:08:39.362800 | TASK [bindep : Look for bindep fallback file] 2025-11-19 00:08:39.400308 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.412213 | 2025-11-19 00:08:39.412447 | TASK [bindep : Define bindep_file fact] 2025-11-19 00:08:39.439914 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.447800 | 2025-11-19 00:08:39.447950 | TASK [bindep : Include bindep tasks] 2025-11-19 00:08:39.483593 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.491287 | 2025-11-19 00:08:39.491451 | TASK [bindep : Include install tasks] 2025-11-19 00:08:39.516865 | controller | skipping: Conditional result was False 2025-11-19 00:08:39.523840 | 2025-11-19 00:08:39.524009 | LOOP [bindep : Include package tasks] 2025-11-19 00:08:39.582379 | 2025-11-19 00:08:39.582610 | TASK [Run test-setup role] 2025-11-19 00:08:39.606449 | controller | ok 2025-11-19 00:08:39.627579 | 2025-11-19 00:08:39.627771 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-19 00:08:39.843824 | controller | ok 2025-11-19 00:08:39.850729 | 2025-11-19 00:08:39.850888 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-19 00:08:40.398021 | controller | skipping: Conditional result was False 2025-11-19 00:08:40.438622 | 2025-11-19 00:08:40.438764 | PLAY RECAP 2025-11-19 00:08:40.438828 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-19 00:08:40.438859 | 2025-11-19 00:08:40.577182 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-19 00:08:40.578171 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-19 00:08:41.205858 | 2025-11-19 00:08:41.206009 | PLAY [controller] 2025-11-19 00:08:41.226406 | 2025-11-19 00:08:41.226495 | TASK [Create the /root directory] 2025-11-19 00:08:41.623564 | controller | ok 2025-11-19 00:08:41.634955 | 2025-11-19 00:08:41.635104 | TASK [Install glibc-langpack-en] 2025-11-19 00:08:45.590490 | controller | ok: Nothing to do 2025-11-19 00:08:45.597791 | 2025-11-19 00:08:45.597961 | TASK [Ensure controller directory exists] 2025-11-19 00:08:45.823540 | controller | changed 2025-11-19 00:08:45.838154 | 2025-11-19 00:08:45.838287 | TASK [Install container runtime] 2025-11-19 00:08:45.924020 | controller | ok 2025-11-19 00:08:45.976746 | 2025-11-19 00:08:45.976923 | LOOP [ensure-podman : Find distribution installation] 2025-11-19 00:08:46.009525 | controller | ok: "/var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-11-19 00:08:46.021539 | controller | included: /var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-11-19 00:08:46.029806 | 2025-11-19 00:08:46.029878 | TASK [ensure-podman : Install podman (RedHat)] 2025-11-19 00:09:54.913311 | controller | changed 2025-11-19 00:09:54.929219 | 2025-11-19 00:09:54.929371 | TASK [ensure-podman : Fetch podman version] 2025-11-19 00:09:55.491140 | controller | Client: Podman Engine 2025-11-19 00:09:55.521224 | controller | Version: 4.6.2 2025-11-19 00:09:55.521260 | controller | API Version: 4.6.2 2025-11-19 00:09:55.521268 | controller | Go Version: go1.19.12 2025-11-19 00:09:55.521288 | controller | Built: Mon Aug 28 19:38:31 2023 2025-11-19 00:09:55.521296 | controller | OS/Arch: linux/amd64 2025-11-19 00:09:55.974168 | controller | ok: Runtime: 0:00:00.185449 2025-11-19 00:09:55.991817 | 2025-11-19 00:09:55.992036 | TASK [ensure-podman : Print podman version installed] 2025-11-19 00:09:56.036012 | Podman version: Client: Podman Engine 2025-11-19 00:09:56.036334 | Version: 4.6.2 2025-11-19 00:09:56.036399 | API Version: 4.6.2 2025-11-19 00:09:56.036446 | Go Version: go1.19.12 2025-11-19 00:09:56.036497 | Built: Mon Aug 28 19:38:31 2023 2025-11-19 00:09:56.036562 | OS/Arch: linux/amd64 2025-11-19 00:09:56.051825 | 2025-11-19 00:09:56.051994 | TASK [ensure-podman : Validate podman engine] 2025-11-19 00:09:56.598323 | controller | skipping: Conditional result was False 2025-11-19 00:09:56.615184 | 2025-11-19 00:09:56.615938 | TASK [ensure-podman : Set up docker compatability socket] 2025-11-19 00:09:56.643971 | controller | skipping: Conditional result was False 2025-11-19 00:09:56.670773 | 2025-11-19 00:09:56.670928 | TASK [Ensure python3.8 is present] 2025-11-19 00:09:56.699654 | controller | skipping: Conditional result was False 2025-11-19 00:09:56.708759 | 2025-11-19 00:09:56.708856 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-19 00:09:56.735449 | controller | ok 2025-11-19 00:09:56.763804 | 2025-11-19 00:09:56.763929 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-19 00:09:58.460556 | controller | ok: Nothing to do 2025-11-19 00:09:58.477087 | 2025-11-19 00:09:58.477259 | TASK [our-ensure-python : Also install python3-devel] 2025-11-19 00:10:13.860887 | controller | changed 2025-11-19 00:10:13.893075 | 2025-11-19 00:10:13.893284 | TASK [Run ensure-virtualenv role] 2025-11-19 00:10:13.926166 | controller | ok 2025-11-19 00:10:14.008917 | 2025-11-19 00:10:14.009102 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-19 00:10:14.224506 | controller | /usr/bin/virtualenv 2025-11-19 00:10:14.543518 | controller | ok: Runtime: 0:00:00.004701 2025-11-19 00:10:14.559123 | 2025-11-19 00:10:14.559369 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-19 00:10:14.591408 | controller | skipping: Conditional result was False 2025-11-19 00:10:14.591806 | controller | ok: All items complete 2025-11-19 00:10:14.591843 | 2025-11-19 00:10:14.629647 | 2025-11-19 00:10:14.629946 | TASK [Find the full path of the Python interpreter] 2025-11-19 00:10:14.868623 | controller | /usr/bin/python3 2025-11-19 00:10:15.183657 | controller | ok 2025-11-19 00:10:15.193028 | 2025-11-19 00:10:15.193199 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-19 00:10:16.205188 | controller | created virtual environment CPython3.11.0.final.0-64 in 554ms 2025-11-19 00:10:16.235938 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-19 00:10:16.236129 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2025-11-19 00:10:16.236141 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-19 00:10:16.236155 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-19 00:10:16.274016 | controller | changed 2025-11-19 00:10:16.292602 | 2025-11-19 00:10:16.292819 | TASK [Set selinux package] 2025-11-19 00:10:16.326901 | controller | ok 2025-11-19 00:10:16.340514 | 2025-11-19 00:10:16.340753 | TASK [Set selinux package (Fedora)] 2025-11-19 00:10:16.387006 | controller | ok 2025-11-19 00:10:16.395647 | 2025-11-19 00:10:16.395785 | TASK [Install selinux into virtualenv] 2025-11-19 00:10:29.969451 | controller | Collecting selinux-please-lie-to-me 2025-11-19 00:10:42.230801 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-19 00:10:42.532389 | controller | Collecting setuptools<50.0.0 2025-11-19 00:10:42.545319 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-19 00:10:42.580186 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.1 MB/s eta 0:00:00 2025-11-19 00:10:42.660403 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-19 00:10:42.660622 | controller | Attempting uninstall: setuptools 2025-11-19 00:10:42.663009 | controller | Found existing installation: setuptools 62.6.0 2025-11-19 00:10:42.722049 | controller | Uninstalling setuptools-62.6.0: 2025-11-19 00:10:42.730279 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-19 00:10:43.075863 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-19 00:10:54.596957 | controller | 2025-11-19 00:10:54.674576 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-19 00:10:54.674625 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-19 00:10:54.972035 | controller | ok: Runtime: 0:00:38.051506 2025-11-19 00:10:54.988453 | 2025-11-19 00:10:54.988635 | TASK [Install pytest-forked into virtualenv] 2025-11-19 00:11:04.791634 | controller | Collecting pytest-forked 2025-11-19 00:11:17.113883 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-19 00:11:17.159643 | controller | Collecting py 2025-11-19 00:11:17.162962 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-19 00:11:17.186976 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.6 MB/s eta 0:00:00 2025-11-19 00:11:17.305839 | controller | Collecting pytest>=3.10 2025-11-19 00:11:17.313196 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-11-19 00:11:17.332268 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 22.5 MB/s eta 0:00:00 2025-11-19 00:11:17.375833 | controller | Collecting iniconfig>=1.0.1 2025-11-19 00:11:17.379775 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-11-19 00:11:17.418826 | controller | Collecting packaging>=22 2025-11-19 00:11:17.424618 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-19 00:11:17.430684 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 16.1 MB/s eta 0:00:00 2025-11-19 00:11:17.465806 | controller | Collecting pluggy<2,>=1.5 2025-11-19 00:11:17.474401 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-19 00:11:17.521205 | controller | Collecting pygments>=2.7.2 2025-11-19 00:11:17.525790 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-19 00:11:17.541115 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 96.7 MB/s eta 0:00:00 2025-11-19 00:11:17.612111 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-11-19 00:11:18.631312 | 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.1 pytest-forked-1.6.0 2025-11-19 00:11:18.639845 | controller | 2025-11-19 00:11:18.707574 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-19 00:11:18.707618 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-19 00:11:19.074880 | controller | ok: Runtime: 0:00:23.472450 2025-11-19 00:11:19.093503 | 2025-11-19 00:11:19.093744 | TASK [Update pip] 2025-11-19 00:11:19.650463 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-11-19 00:11:29.482797 | controller | Collecting pip 2025-11-19 00:11:41.804034 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-19 00:11:41.858740 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 34.4 MB/s eta 0:00:00 2025-11-19 00:11:41.922913 | controller | Installing collected packages: pip 2025-11-19 00:11:41.923126 | controller | Attempting uninstall: pip 2025-11-19 00:11:41.925253 | controller | Found existing installation: pip 22.2.2 2025-11-19 00:11:42.060056 | controller | Uninstalling pip-22.2.2: 2025-11-19 00:11:42.074864 | controller | Successfully uninstalled pip-22.2.2 2025-11-19 00:11:42.869253 | controller | Successfully installed pip-25.3 2025-11-19 00:11:43.179545 | controller | ok: Runtime: 0:00:23.592133 2025-11-19 00:11:43.197582 | 2025-11-19 00:11:43.197873 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-11-19 00:11:43.446248 | controller | changed 2025-11-19 00:11:43.459291 | 2025-11-19 00:11:43.459460 | TASK [Install ansible into virtualenv] 2025-11-19 00:11:43.995874 | controller | Processing ./src/github.com/ansible/ansible 2025-11-19 00:11:43.999272 | controller | Installing build dependencies: started 2025-11-19 00:12:06.930640 | controller | Installing build dependencies: finished with status 'done' 2025-11-19 00:12:06.931881 | controller | Getting requirements to build wheel: started 2025-11-19 00:12:07.646024 | controller | Getting requirements to build wheel: finished with status 'done' 2025-11-19 00:12:07.647613 | controller | Preparing metadata (pyproject.toml): started 2025-11-19 00:12:08.099093 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-11-19 00:12:08.104942 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2025-11-19 00:12:08.109275 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-11-19 00:12:08.525968 | controller | ERROR 2025-11-19 00:12:08.526254 | controller | { 2025-11-19 00:12:08.526286 | controller | "delta": "0:00:24.461689", 2025-11-19 00:12:08.526307 | controller | "end": "2025-11-19 00:12:08.170960", 2025-11-19 00:12:08.526325 | controller | "msg": "non-zero return code", 2025-11-19 00:12:08.526355 | controller | "rc": 1, 2025-11-19 00:12:08.526372 | controller | "start": "2025-11-19 00:11:43.709271" 2025-11-19 00:12:08.526387 | controller | } failure 2025-11-19 00:12:08.529383 | 2025-11-19 00:12:08.529447 | PLAY RECAP 2025-11-19 00:12:08.529502 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-11-19 00:12:08.529530 | 2025-11-19 00:12:08.664831 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-19 00:12:08.665823 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-19 00:12:09.279004 | 2025-11-19 00:12:09.279166 | PLAY [all] 2025-11-19 00:12:09.301297 | 2025-11-19 00:12:09.301402 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-19 00:12:09.510579 | controller | changed: non-zero return code 2025-11-19 00:12:09.519168 | 2025-11-19 00:12:09.519526 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-19 00:12:09.536444 | controller | skipping: Conditional result was False 2025-11-19 00:12:09.543894 | 2025-11-19 00:12:09.543998 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-19 00:12:09.569855 | 2025-11-19 00:12:09.570077 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-19 00:12:09.605147 | 2025-11-19 00:12:09.605315 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-19 00:12:09.619999 | controller | skipping: Conditional result was False 2025-11-19 00:12:09.628087 | 2025-11-19 00:12:09.628198 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-19 00:12:09.663373 | 2025-11-19 00:12:09.663546 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-19 00:12:09.678682 | controller | skipping: Conditional result was False 2025-11-19 00:12:09.685324 | 2025-11-19 00:12:09.685516 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-19 00:12:09.708128 | controller | skipping: Conditional result was False 2025-11-19 00:12:09.715278 | 2025-11-19 00:12:09.715367 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-19 00:12:09.742724 | controller | skipping: Conditional result was False 2025-11-19 00:12:09.770399 | 2025-11-19 00:12:09.770544 | PLAY RECAP 2025-11-19 00:12:09.770594 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-19 00:12:09.770615 | 2025-11-19 00:12:09.887943 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-19 00:12:09.888891 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-19 00:12:10.520995 | 2025-11-19 00:12:10.521127 | PLAY [all:!appliance*] 2025-11-19 00:12:10.544623 | 2025-11-19 00:12:10.544791 | TASK [unregister the node] 2025-11-19 00:12:11.077828 | controller | skipping: Conditional result was False 2025-11-19 00:12:11.091445 | 2025-11-19 00:12:11.091607 | TASK [include_role : fetch-output] 2025-11-19 00:12:11.152111 | controller | ok 2025-11-19 00:12:11.190276 | 2025-11-19 00:12:11.190428 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-19 00:12:11.267476 | controller | skipping: Conditional result was False 2025-11-19 00:12:11.282165 | 2025-11-19 00:12:11.282329 | TASK [fetch-output : Set log path for single node] 2025-11-19 00:12:11.351714 | controller | ok 2025-11-19 00:12:11.366469 | 2025-11-19 00:12:11.366661 | LOOP [fetch-output : Ensure local output dirs] 2025-11-19 00:12:11.835142 | controller -> localhost | ok: "/var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/logs" 2025-11-19 00:12:12.079394 | controller -> localhost | changed: "/var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/artifacts" 2025-11-19 00:12:12.343429 | controller -> localhost | changed: "/var/lib/zuul/builds/ed744bfaf5da4a2696e0133f79bc9c80/work/docs" 2025-11-19 00:12:12.378919 | 2025-11-19 00:12:12.379116 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-19 00:12:13.090753 | controller | changed: 2025-11-19 00:12:13.091165 | controller | .d..t...... ./ 2025-11-19 00:12:13.091229 | controller | cd+++++++++ controller/ 2025-11-19 00:12:13.091302 | controller | changed: All items complete 2025-11-19 00:12:13.091348 | 2025-11-19 00:12:13.660601 | controller | changed: .d..t...... ./ 2025-11-19 00:12:14.160940 | controller | changed: .d..t...... ./ 2025-11-19 00:12:14.185866 | 2025-11-19 00:12:14.186020 | TASK [include_role : fetch-output-openshift] 2025-11-19 00:12:14.200805 | controller | skipping: Conditional result was False 2025-11-19 00:12:14.210839 | 2025-11-19 00:12:14.210979 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-19 00:12:14.240248 | controller | skipping: Conditional result was False 2025-11-19 00:12:14.251595 | controller | skipping: Conditional result was False 2025-11-19 00:12:14.301606 | 2025-11-19 00:12:14.301766 | PLAY [localhost] 2025-11-19 00:12:14.316554 | 2025-11-19 00:12:14.316787 | TASK [Run Zuul manifest role] 2025-11-19 00:12:14.339456 | localhost | ok 2025-11-19 00:12:14.360515 | 2025-11-19 00:12:14.360680 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-19 00:12:14.813433 | localhost | changed 2025-11-19 00:12:14.821058 | 2025-11-19 00:12:14.821164 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-19 00:12:14.869908 | localhost | ok 2025-11-19 00:12:14.890189 | 2025-11-19 00:12:14.890357 | TASK [Set zuul-log-path fact] 2025-11-19 00:12:14.914962 | localhost | ok 2025-11-19 00:12:14.939902 | 2025-11-19 00:12:14.940047 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-19 00:12:14.976458 | localhost | ok 2025-11-19 00:12:14.985822 | 2025-11-19 00:12:14.985890 | LOOP [Run upload-logs-swift role] 2025-11-19 00:12:15.032129 | localhost | Output suppressed because no_log was given 2025-11-19 00:12:15.058588 | 2025-11-19 00:12:15.058721 | TASK [Set zuul-log-path fact] 2025-11-19 00:12:15.093787 | localhost | skipping: Conditional result was False 2025-11-19 00:12:15.101547 | 2025-11-19 00:12:15.101641 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-19 00:12:15.640304 | localhost -> localhost | ok: Runtime: 0:00:00.010192 2025-11-19 00:12:15.647421 | 2025-11-19 00:12:15.647550 | TASK [upload-logs-swift : Upload logs to swift]