2025-11-14 00:20:47.482123 | Job console starting... 2025-11-14 00:20:47.491718 | Updating repositories 2025-11-14 00:20:47.599527 | Preparing job workspace 2025-11-14 00:20:51.741759 | Running Ansible setup... 2025-11-14 00:20:56.525203 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-14 00:20:57.171150 | 2025-11-14 00:20:57.171314 | PLAY [localhost] 2025-11-14 00:20:57.180373 | 2025-11-14 00:20:57.180464 | TASK [Gathering Facts] 2025-11-14 00:20:58.302284 | localhost | ok 2025-11-14 00:20:58.322893 | 2025-11-14 00:20:58.323079 | TASK [Setup log path fact] 2025-11-14 00:20:58.359935 | localhost | ok 2025-11-14 00:20:58.380701 | 2025-11-14 00:20:58.380856 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-14 00:20:58.414184 | localhost | ok 2025-11-14 00:20:58.426193 | 2025-11-14 00:20:58.426314 | TASK [emit-job-header : Print job information] 2025-11-14 00:20:58.470302 | # Job Information 2025-11-14 00:20:58.470541 | Ansible Version: 2.15.12 2025-11-14 00:20:58.470590 | Job: ansible-test-sanity-docker-milestone 2025-11-14 00:20:58.470629 | Pipeline: periodic 2025-11-14 00:20:58.470656 | Executor: ze04.softwarefactory-project.io 2025-11-14 00:20:58.470718 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-14 00:20:58.470758 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/8a0/ansible/8a01cf186a614fe882d1aa912de5fd0b/ 2025-11-14 00:20:58.470789 | Event ID: cd9e3d3ce9024090aa7497036110b86b 2025-11-14 00:20:58.476799 | 2025-11-14 00:20:58.476895 | LOOP [emit-job-header : Print node information] 2025-11-14 00:20:58.583429 | localhost | ok: 2025-11-14 00:20:58.583818 | localhost | # Node Information 2025-11-14 00:20:58.583855 | localhost | Inventory Hostname: controller 2025-11-14 00:20:58.583877 | localhost | Hostname: np0005522221 2025-11-14 00:20:58.583896 | localhost | Username: zuul 2025-11-14 00:20:58.583920 | localhost | Distro: Fedora 37 2025-11-14 00:20:58.583939 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-11-14 00:20:58.583956 | localhost | Region: ca-ymq-1 2025-11-14 00:20:58.583972 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-14 00:20:58.583988 | localhost | Product Name: OpenStack Nova 2025-11-14 00:20:58.584005 | localhost | Interface IP: 162.253.55.213 2025-11-14 00:20:58.603304 | 2025-11-14 00:20:58.603589 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-14 00:20:59.092934 | localhost -> localhost | changed 2025-11-14 00:20:59.099144 | 2025-11-14 00:20:59.099263 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-14 00:21:00.069325 | localhost -> localhost | changed 2025-11-14 00:21:00.092786 | 2025-11-14 00:21:00.092870 | PLAY [all:!appliance*] 2025-11-14 00:21:00.110512 | 2025-11-14 00:21:00.110636 | TASK [include_role : start-zuul-console] 2025-11-14 00:21:00.142861 | controller | ok 2025-11-14 00:21:00.157200 | 2025-11-14 00:21:00.157310 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-14 00:21:00.567959 | controller | ok 2025-11-14 00:21:00.582058 | 2025-11-14 00:21:00.582147 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-14 00:21:01.690457 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-14 00:21:01.702481 | 2025-11-14 00:21:01.702607 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-14 00:21:02.249450 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.280792 | 2025-11-14 00:21:02.281077 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-14 00:21:02.309930 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.321130 | 2025-11-14 00:21:02.321240 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-14 00:21:02.358181 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.369144 | 2025-11-14 00:21:02.369297 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-14 00:21:02.404965 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.414742 | 2025-11-14 00:21:02.414848 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-14 00:21:02.440519 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.452243 | 2025-11-14 00:21:02.452390 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-14 00:21:02.477797 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.497651 | 2025-11-14 00:21:02.497823 | TASK [Disable Fedora Modular] 2025-11-14 00:21:02.764389 | controller | changed 2025-11-14 00:21:02.782230 | 2025-11-14 00:21:02.782435 | TASK [Enable EPEL] 2025-11-14 00:21:02.819722 | controller | skipping: Conditional result was False 2025-11-14 00:21:02.833599 | 2025-11-14 00:21:02.833817 | TASK [Register the RHEL node] 2025-11-14 00:21:03.402125 | 2025-11-14 00:21:03.402455 | TASK [Show the subscription-manager status] 2025-11-14 00:21:03.998110 | controller | skipping: Conditional result was False 2025-11-14 00:21:04.013224 | 2025-11-14 00:21:04.013391 | TASK [Enable EPEL on RHEL] 2025-11-14 00:21:04.577306 | controller | skipping: Conditional result was False 2025-11-14 00:21:04.587976 | 2025-11-14 00:21:04.588104 | TASK [Install git and tox] 2025-11-14 00:22:25.254857 | controller | changed 2025-11-14 00:22:25.269148 | 2025-11-14 00:22:25.269306 | TASK [include_role : prepare-workspace] 2025-11-14 00:22:25.302215 | controller | ok 2025-11-14 00:22:25.342301 | 2025-11-14 00:22:25.342488 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-14 00:22:25.579948 | controller | ok 2025-11-14 00:22:25.589233 | 2025-11-14 00:22:25.589328 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-14 00:22:38.092976 | controller | Output suppressed because no_log was given 2025-11-14 00:22:38.104428 | 2025-11-14 00:22:38.104498 | TASK [include_role : prepare-workspace-openshift] 2025-11-14 00:22:38.140389 | controller | skipping: Conditional result was False 2025-11-14 00:22:38.186334 | 2025-11-14 00:22:38.186496 | PLAY [all:!appliance] 2025-11-14 00:22:38.208542 | 2025-11-14 00:22:38.208634 | TASK [Run add-build-sshkey role (RSA)] 2025-11-14 00:22:38.232452 | controller | ok 2025-11-14 00:22:38.251275 | 2025-11-14 00:22:38.251438 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-14 00:22:38.522598 | controller -> localhost | ok 2025-11-14 00:22:38.532843 | 2025-11-14 00:22:38.532963 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-14 00:22:38.566052 | controller | ok 2025-11-14 00:22:38.587524 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-14 00:22:38.596728 | 2025-11-14 00:22:38.596819 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-14 00:22:39.314819 | controller -> localhost | Generating public/private rsa key pair. 2025-11-14 00:22:39.315105 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_rsa. 2025-11-14 00:22:39.315135 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_rsa.pub. 2025-11-14 00:22:39.315156 | controller -> localhost | The key fingerprint is: 2025-11-14 00:22:39.315176 | controller -> localhost | SHA256:TVWZmCj9PxTJGN6zsQg9AEgh6Aph4/Vk6mr7KU1nEAE zuul-build-sshkey 2025-11-14 00:22:39.315198 | controller -> localhost | The key's randomart image is: 2025-11-14 00:22:39.315217 | controller -> localhost | +---[RSA 2048]----+ 2025-11-14 00:22:39.315236 | controller -> localhost | | E.oo.oo.o..oB.+ | 2025-11-14 00:22:39.315256 | controller -> localhost | |.o.o +. . o=+.* | 2025-11-14 00:22:39.315275 | controller -> localhost | |ooo * .o.+ +. | 2025-11-14 00:22:39.315293 | controller -> localhost | |...o . o ..o.= | 2025-11-14 00:22:39.315310 | controller -> localhost | |... . S . .oo | 2025-11-14 00:22:39.315346 | controller -> localhost | |. o o o | 2025-11-14 00:22:39.315370 | controller -> localhost | | + o . | 2025-11-14 00:22:39.315391 | controller -> localhost | | + .. | 2025-11-14 00:22:39.315410 | controller -> localhost | |..+o | 2025-11-14 00:22:39.315431 | controller -> localhost | +----[SHA256]-----+ 2025-11-14 00:22:39.315482 | controller -> localhost | ok: Runtime: 0:00:00.246277 2025-11-14 00:22:39.324877 | 2025-11-14 00:22:39.325020 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-14 00:22:39.358440 | controller | ok 2025-11-14 00:22:39.371411 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-14 00:22:39.383324 | 2025-11-14 00:22:39.383470 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-14 00:22:39.411554 | controller | skipping: Conditional result was False 2025-11-14 00:22:39.419655 | 2025-11-14 00:22:39.419766 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-14 00:22:39.879230 | controller | changed 2025-11-14 00:22:39.892952 | 2025-11-14 00:22:39.893105 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-14 00:22:40.126271 | controller | ok 2025-11-14 00:22:40.136291 | 2025-11-14 00:22:40.136414 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-14 00:22:40.766818 | controller | changed 2025-11-14 00:22:40.775157 | 2025-11-14 00:22:40.775301 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-14 00:22:41.355216 | controller | changed 2025-11-14 00:22:41.361238 | 2025-11-14 00:22:41.361308 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-14 00:22:41.396120 | controller | skipping: Conditional result was False 2025-11-14 00:22:41.411117 | 2025-11-14 00:22:41.411296 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-14 00:22:41.868128 | controller -> localhost | changed 2025-11-14 00:22:41.881168 | 2025-11-14 00:22:41.881261 | TASK [add-build-sshkey : Add back temp key] 2025-11-14 00:22:42.272473 | controller -> localhost | Identity added: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_rsa (zuul-build-sshkey) 2025-11-14 00:22:42.272838 | controller -> localhost | ok: Runtime: 0:00:00.008095 2025-11-14 00:22:42.280769 | 2025-11-14 00:22:42.280842 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-14 00:22:42.634991 | controller | ok 2025-11-14 00:22:42.647450 | 2025-11-14 00:22:42.647587 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-14 00:22:42.687122 | controller | skipping: Conditional result was False 2025-11-14 00:22:42.717591 | 2025-11-14 00:22:42.717859 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-14 00:22:42.753051 | controller | ok 2025-11-14 00:22:42.776103 | 2025-11-14 00:22:42.776205 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-14 00:22:43.078251 | controller -> localhost | ok 2025-11-14 00:22:43.086167 | 2025-11-14 00:22:43.086260 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-14 00:22:43.121849 | controller | ok 2025-11-14 00:22:43.133458 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-14 00:22:43.139919 | 2025-11-14 00:22:43.139989 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-14 00:22:43.515020 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-14 00:22:43.515296 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_ecdsa. 2025-11-14 00:22:43.515325 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_ecdsa.pub. 2025-11-14 00:22:43.515390 | controller -> localhost | The key fingerprint is: 2025-11-14 00:22:43.515411 | controller -> localhost | SHA256:f55Oh4EoczRQqWUTYC11Rcnf7eTe06sukbN7imWtvO0 zuul-build-sshkey 2025-11-14 00:22:43.515431 | controller -> localhost | The key's randomart image is: 2025-11-14 00:22:43.515450 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-14 00:22:43.515468 | controller -> localhost | | +=+o.+o. | 2025-11-14 00:22:43.515485 | controller -> localhost | | ...*. o | 2025-11-14 00:22:43.515502 | controller -> localhost | | =o. . ..| 2025-11-14 00:22:43.515518 | controller -> localhost | | .. o . . +| 2025-11-14 00:22:43.515536 | controller -> localhost | | o S . o + | 2025-11-14 00:22:43.515568 | controller -> localhost | | + . +.o o| 2025-11-14 00:22:43.515588 | controller -> localhost | | .oB...o| 2025-11-14 00:22:43.515606 | controller -> localhost | | =*o+ .+| 2025-11-14 00:22:43.515623 | controller -> localhost | | . B%E..o| 2025-11-14 00:22:43.515640 | controller -> localhost | +----[SHA256]-----+ 2025-11-14 00:22:43.515707 | controller -> localhost | ok: Runtime: 0:00:00.017659 2025-11-14 00:22:43.523119 | 2025-11-14 00:22:43.523183 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-14 00:22:43.565998 | controller | ok 2025-11-14 00:22:43.577730 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-14 00:22:43.590003 | 2025-11-14 00:22:43.590089 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-14 00:22:43.626252 | controller | skipping: Conditional result was False 2025-11-14 00:22:43.636466 | 2025-11-14 00:22:43.636614 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-14 00:22:43.933156 | controller | changed 2025-11-14 00:22:43.946422 | 2025-11-14 00:22:43.946573 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-14 00:22:44.180804 | controller | ok 2025-11-14 00:22:44.191597 | 2025-11-14 00:22:44.191797 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-14 00:22:44.809593 | controller | changed 2025-11-14 00:22:44.816264 | 2025-11-14 00:22:44.816401 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-14 00:22:45.490920 | controller | changed 2025-11-14 00:22:45.561902 | 2025-11-14 00:22:45.562065 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-14 00:22:45.598122 | controller | skipping: Conditional result was False 2025-11-14 00:22:45.605897 | 2025-11-14 00:22:45.605992 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-14 00:22:45.886810 | controller -> localhost | changed 2025-11-14 00:22:45.899422 | 2025-11-14 00:22:45.899545 | TASK [add-build-sshkey : Add back temp key] 2025-11-14 00:22:46.211308 | controller -> localhost | Identity added: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/8a01cf186a614fe882d1aa912de5fd0b_id_ecdsa (zuul-build-sshkey) 2025-11-14 00:22:46.211901 | controller -> localhost | ok: Runtime: 0:00:00.015505 2025-11-14 00:22:46.232347 | 2025-11-14 00:22:46.232567 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-14 00:22:46.448594 | controller | ok 2025-11-14 00:22:46.458010 | 2025-11-14 00:22:46.458117 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-14 00:22:46.484388 | controller | skipping: Conditional result was False 2025-11-14 00:22:46.504824 | 2025-11-14 00:22:46.504997 | TASK [include_role : remove-zuul-sshkey] 2025-11-14 00:22:46.530624 | controller | skipping: Conditional result was False 2025-11-14 00:22:46.542097 | 2025-11-14 00:22:46.542229 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-14 00:27:47.140943 | controller | ok: "logs" 2025-11-14 00:27:47.141388 | controller | ok: All items complete 2025-11-14 00:27:47.141451 | 2025-11-14 00:27:47.369538 | controller | ok: "artifacts" 2025-11-14 00:27:47.607459 | controller | ok: "docs" 2025-11-14 00:27:47.631195 | 2025-11-14 00:27:47.631367 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-14 00:27:47.901517 | controller | changed: "logs" 2025-11-14 00:27:48.099895 | controller | changed: "artifacts" 2025-11-14 00:27:48.293942 | controller | changed: "docs" 2025-11-14 00:27:48.330547 | 2025-11-14 00:27:48.330772 | PLAY RECAP 2025-11-14 00:27:48.330889 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-14 00:27:48.330951 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-14 00:27:48.330991 | 2025-11-14 00:27:48.468670 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-14 00:27:48.469620 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-14 00:27:49.113986 | 2025-11-14 00:27:49.114109 | PLAY [all] 2025-11-14 00:27:49.137467 | 2025-11-14 00:27:49.137624 | TASK [Install binary dependencies] 2025-11-14 00:27:49.192071 | controller | ok 2025-11-14 00:27:49.220098 | 2025-11-14 00:27:49.220242 | TASK [bindep : Include find tasks] 2025-11-14 00:27:49.250545 | controller | ok 2025-11-14 00:27:49.258336 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-14 00:27:49.264543 | 2025-11-14 00:27:49.264608 | TASK [bindep : Look for bindep.txt] 2025-11-14 00:27:49.823293 | controller | ok 2025-11-14 00:27:49.836862 | 2025-11-14 00:27:49.837021 | TASK [bindep : Define bindep_file fact] 2025-11-14 00:27:49.864354 | controller | skipping: Conditional result was False 2025-11-14 00:27:49.878838 | 2025-11-14 00:27:49.879023 | TASK [bindep : Look for other-requirements.txt] 2025-11-14 00:27:50.112003 | controller | ok 2025-11-14 00:27:50.123947 | 2025-11-14 00:27:50.124125 | TASK [bindep : Define bindep_file fact] 2025-11-14 00:27:50.150853 | controller | skipping: Conditional result was False 2025-11-14 00:27:50.165152 | 2025-11-14 00:27:50.165353 | TASK [bindep : Look for bindep fallback file] 2025-11-14 00:27:50.191159 | controller | skipping: Conditional result was False 2025-11-14 00:27:50.203501 | 2025-11-14 00:27:50.203669 | TASK [bindep : Define bindep_file fact] 2025-11-14 00:27:50.228778 | controller | skipping: Conditional result was False 2025-11-14 00:27:50.237633 | 2025-11-14 00:27:50.237812 | TASK [bindep : Include bindep tasks] 2025-11-14 00:27:50.273393 | controller | skipping: Conditional result was False 2025-11-14 00:27:50.281998 | 2025-11-14 00:27:50.282123 | TASK [bindep : Include install tasks] 2025-11-14 00:27:50.307933 | controller | skipping: Conditional result was False 2025-11-14 00:27:50.316540 | 2025-11-14 00:27:50.316659 | LOOP [bindep : Include package tasks] 2025-11-14 00:27:50.389231 | 2025-11-14 00:27:50.389457 | TASK [Run test-setup role] 2025-11-14 00:27:50.414931 | controller | ok 2025-11-14 00:27:50.440135 | 2025-11-14 00:27:50.440347 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-14 00:27:50.645313 | controller | ok 2025-11-14 00:27:50.660029 | 2025-11-14 00:27:50.660185 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-14 00:27:51.210889 | controller | skipping: Conditional result was False 2025-11-14 00:27:51.268877 | 2025-11-14 00:27:51.269019 | PLAY RECAP 2025-11-14 00:27:51.269074 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-14 00:27:51.269102 | 2025-11-14 00:27:51.376361 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-14 00:27:51.377422 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-14 00:27:52.048015 | 2025-11-14 00:27:52.048178 | PLAY [controller] 2025-11-14 00:27:52.069636 | 2025-11-14 00:27:52.069836 | TASK [Create the /root directory] 2025-11-14 00:27:52.682557 | controller | ok 2025-11-14 00:27:52.698252 | 2025-11-14 00:27:52.698485 | TASK [Install glibc-langpack-en] 2025-11-14 00:27:56.557122 | controller | ok: Nothing to do 2025-11-14 00:27:56.564591 | 2025-11-14 00:27:56.564808 | TASK [Ensure controller directory exists] 2025-11-14 00:27:56.775984 | controller | changed 2025-11-14 00:27:56.790795 | 2025-11-14 00:27:56.791003 | TASK [Install container runtime] 2025-11-14 00:27:56.851760 | controller | ok 2025-11-14 00:27:56.913655 | 2025-11-14 00:27:56.913875 | LOOP [ensure-podman : Find distribution installation] 2025-11-14 00:27:56.940307 | controller | ok: "/var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-11-14 00:27:56.947814 | controller | included: /var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-11-14 00:27:56.954844 | 2025-11-14 00:27:56.954968 | TASK [ensure-podman : Install podman (RedHat)] 2025-11-14 00:29:02.676190 | controller | changed 2025-11-14 00:29:02.690534 | 2025-11-14 00:29:02.690723 | TASK [ensure-podman : Fetch podman version] 2025-11-14 00:29:03.261691 | controller | Client: Podman Engine 2025-11-14 00:29:03.293853 | controller | Version: 4.6.2 2025-11-14 00:29:03.293887 | controller | API Version: 4.6.2 2025-11-14 00:29:03.293894 | controller | Go Version: go1.19.12 2025-11-14 00:29:03.293910 | controller | Built: Mon Aug 28 19:38:31 2023 2025-11-14 00:29:03.293917 | controller | OS/Arch: linux/amd64 2025-11-14 00:29:03.754750 | controller | ok: Runtime: 0:00:00.194741 2025-11-14 00:29:03.769025 | 2025-11-14 00:29:03.769182 | TASK [ensure-podman : Print podman version installed] 2025-11-14 00:29:03.810557 | Podman version: Client: Podman Engine 2025-11-14 00:29:03.810881 | Version: 4.6.2 2025-11-14 00:29:03.810947 | API Version: 4.6.2 2025-11-14 00:29:03.810995 | Go Version: go1.19.12 2025-11-14 00:29:03.811039 | Built: Mon Aug 28 19:38:31 2023 2025-11-14 00:29:03.811084 | OS/Arch: linux/amd64 2025-11-14 00:29:03.823848 | 2025-11-14 00:29:03.824034 | TASK [ensure-podman : Validate podman engine] 2025-11-14 00:29:04.374885 | controller | skipping: Conditional result was False 2025-11-14 00:29:04.389434 | 2025-11-14 00:29:04.389639 | TASK [ensure-podman : Set up docker compatability socket] 2025-11-14 00:29:04.407158 | controller | skipping: Conditional result was False 2025-11-14 00:29:04.427909 | 2025-11-14 00:29:04.428085 | TASK [Ensure python3.8 is present] 2025-11-14 00:29:04.445127 | controller | skipping: Conditional result was False 2025-11-14 00:29:04.455222 | 2025-11-14 00:29:04.455389 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-14 00:29:04.480619 | controller | ok 2025-11-14 00:29:04.510462 | 2025-11-14 00:29:04.510625 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-14 00:29:05.826191 | controller | ok: Nothing to do 2025-11-14 00:29:05.834942 | 2025-11-14 00:29:05.835036 | TASK [our-ensure-python : Also install python3-devel] 2025-11-14 00:29:14.704448 | controller | changed 2025-11-14 00:29:14.729888 | 2025-11-14 00:29:14.730087 | TASK [Run ensure-virtualenv role] 2025-11-14 00:29:14.758372 | controller | ok 2025-11-14 00:29:14.791186 | 2025-11-14 00:29:14.791477 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-14 00:29:15.069463 | controller | /usr/bin/virtualenv 2025-11-14 00:29:15.373752 | controller | ok: Runtime: 0:00:00.004784 2025-11-14 00:29:15.389867 | 2025-11-14 00:29:15.390070 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-14 00:29:15.426711 | controller | skipping: Conditional result was False 2025-11-14 00:29:15.427120 | controller | ok: All items complete 2025-11-14 00:29:15.427165 | 2025-11-14 00:29:15.455966 | 2025-11-14 00:29:15.456326 | TASK [Find the full path of the Python interpreter] 2025-11-14 00:29:15.700466 | controller | /usr/bin/python3 2025-11-14 00:29:16.005219 | controller | ok 2025-11-14 00:29:16.020583 | 2025-11-14 00:29:16.020807 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-14 00:29:16.888145 | controller | created virtual environment CPython3.11.0.final.0-64 in 476ms 2025-11-14 00:29:16.903809 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-14 00:29:16.903843 | 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-14 00:29:16.903855 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-14 00:29:16.903869 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-14 00:29:17.083869 | controller | changed 2025-11-14 00:29:17.098439 | 2025-11-14 00:29:17.098627 | TASK [Set selinux package] 2025-11-14 00:29:17.140765 | controller | ok 2025-11-14 00:29:17.153066 | 2025-11-14 00:29:17.153207 | TASK [Set selinux package (Fedora)] 2025-11-14 00:29:17.213337 | controller | ok 2025-11-14 00:29:17.224897 | 2025-11-14 00:29:17.225033 | TASK [Install selinux into virtualenv] 2025-11-14 00:29:42.718750 | controller | Collecting selinux-please-lie-to-me 2025-11-14 00:29:54.961321 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-14 00:29:55.265984 | controller | Collecting setuptools<50.0.0 2025-11-14 00:29:55.270747 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-14 00:29:55.316352 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.1 MB/s eta 0:00:00 2025-11-14 00:29:55.396635 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-14 00:29:55.396853 | controller | Attempting uninstall: setuptools 2025-11-14 00:29:55.399230 | controller | Found existing installation: setuptools 62.6.0 2025-11-14 00:29:55.457750 | controller | Uninstalling setuptools-62.6.0: 2025-11-14 00:29:55.465943 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-14 00:29:55.821261 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-14 00:30:07.338068 | controller | 2025-11-14 00:30:07.422741 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-14 00:30:07.422815 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-14 00:30:07.803415 | controller | ok: Runtime: 0:00:49.952603 2025-11-14 00:30:07.816181 | 2025-11-14 00:30:07.816406 | TASK [Install pytest-forked into virtualenv] 2025-11-14 00:30:17.559306 | controller | Collecting pytest-forked 2025-11-14 00:30:29.902875 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-14 00:30:29.952402 | controller | Collecting py 2025-11-14 00:30:29.957880 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-14 00:30:29.983703 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00 2025-11-14 00:30:30.091862 | controller | Collecting pytest>=3.10 2025-11-14 00:30:30.097403 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-11-14 00:30:30.119536 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 20.7 MB/s eta 0:00:00 2025-11-14 00:30:30.164741 | controller | Collecting iniconfig>=1.0.1 2025-11-14 00:30:30.168442 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-11-14 00:30:30.214368 | controller | Collecting packaging>=22 2025-11-14 00:30:30.217657 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-14 00:30:30.225714 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.5 MB/s eta 0:00:00 2025-11-14 00:30:30.264579 | controller | Collecting pluggy<2,>=1.5 2025-11-14 00:30:30.268101 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-14 00:30:30.319001 | controller | Collecting pygments>=2.7.2 2025-11-14 00:30:30.323068 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-14 00:30:30.352879 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 47.4 MB/s eta 0:00:00 2025-11-14 00:30:30.421961 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-11-14 00:30:31.439601 | 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-14 00:30:31.448218 | controller | 2025-11-14 00:30:31.514068 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-14 00:30:31.514110 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-14 00:30:31.884296 | controller | ok: Runtime: 0:00:23.442252 2025-11-14 00:30:31.890845 | 2025-11-14 00:30:31.890952 | TASK [Update pip] 2025-11-14 00:30:32.456124 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-11-14 00:30:42.279180 | controller | Collecting pip 2025-11-14 00:30:54.478588 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-14 00:30:54.536578 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.5 MB/s eta 0:00:00 2025-11-14 00:30:54.601990 | controller | Installing collected packages: pip 2025-11-14 00:30:54.602107 | controller | Attempting uninstall: pip 2025-11-14 00:30:54.604342 | controller | Found existing installation: pip 22.2.2 2025-11-14 00:30:54.741849 | controller | Uninstalling pip-22.2.2: 2025-11-14 00:30:54.756580 | controller | Successfully uninstalled pip-22.2.2 2025-11-14 00:30:55.560363 | controller | Successfully installed pip-25.3 2025-11-14 00:30:55.968279 | controller | ok: Runtime: 0:00:23.494582 2025-11-14 00:30:55.986122 | 2025-11-14 00:30:55.986329 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-11-14 00:30:56.208710 | controller | changed 2025-11-14 00:30:56.220591 | 2025-11-14 00:30:56.221233 | TASK [Install ansible into virtualenv] 2025-11-14 00:30:56.750458 | controller | Processing ./src/github.com/ansible/ansible 2025-11-14 00:30:56.753952 | controller | Installing build dependencies: started 2025-11-14 00:31:19.510545 | controller | Installing build dependencies: finished with status 'done' 2025-11-14 00:31:19.511101 | controller | Getting requirements to build wheel: started 2025-11-14 00:31:20.261802 | controller | Getting requirements to build wheel: finished with status 'done' 2025-11-14 00:31:20.263012 | controller | Preparing metadata (pyproject.toml): started 2025-11-14 00:31:20.718519 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-11-14 00:31:20.724541 | 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-14 00:31:20.730101 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-11-14 00:31:21.296000 | controller | ERROR 2025-11-14 00:31:21.296332 | controller | { 2025-11-14 00:31:21.296399 | controller | "delta": "0:00:24.334818", 2025-11-14 00:31:21.296443 | controller | "end": "2025-11-14 00:31:20.803645", 2025-11-14 00:31:21.296482 | controller | "msg": "non-zero return code", 2025-11-14 00:31:21.296535 | controller | "rc": 1, 2025-11-14 00:31:21.296574 | controller | "start": "2025-11-14 00:30:56.468827" 2025-11-14 00:31:21.296610 | controller | } failure 2025-11-14 00:31:21.299198 | 2025-11-14 00:31:21.299299 | PLAY RECAP 2025-11-14 00:31:21.299385 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-11-14 00:31:21.299432 | 2025-11-14 00:31:21.449983 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-14 00:31:21.450980 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-14 00:31:22.042547 | 2025-11-14 00:31:22.042734 | PLAY [all] 2025-11-14 00:31:22.074309 | 2025-11-14 00:31:22.074480 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-14 00:31:22.472657 | controller | changed: non-zero return code 2025-11-14 00:31:22.479970 | 2025-11-14 00:31:22.480066 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-14 00:31:22.503762 | controller | skipping: Conditional result was False 2025-11-14 00:31:22.509610 | 2025-11-14 00:31:22.509693 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-14 00:31:22.551198 | 2025-11-14 00:31:22.551473 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-14 00:31:22.586212 | 2025-11-14 00:31:22.586409 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-14 00:31:22.611205 | controller | skipping: Conditional result was False 2025-11-14 00:31:22.622194 | 2025-11-14 00:31:22.622323 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-14 00:31:22.657965 | 2025-11-14 00:31:22.658154 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-14 00:31:22.672739 | controller | skipping: Conditional result was False 2025-11-14 00:31:22.681496 | 2025-11-14 00:31:22.681591 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-14 00:31:22.696289 | controller | skipping: Conditional result was False 2025-11-14 00:31:22.704917 | 2025-11-14 00:31:22.705008 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-14 00:31:22.719570 | controller | skipping: Conditional result was False 2025-11-14 00:31:22.758331 | 2025-11-14 00:31:22.758434 | PLAY RECAP 2025-11-14 00:31:22.758476 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-14 00:31:22.758496 | 2025-11-14 00:31:22.867854 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-14 00:31:22.869631 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-14 00:31:23.506862 | 2025-11-14 00:31:23.506999 | PLAY [all:!appliance*] 2025-11-14 00:31:23.530332 | 2025-11-14 00:31:23.530471 | TASK [unregister the node] 2025-11-14 00:31:24.064553 | controller | skipping: Conditional result was False 2025-11-14 00:31:24.074145 | 2025-11-14 00:31:24.074286 | TASK [include_role : fetch-output] 2025-11-14 00:31:24.128232 | controller | ok 2025-11-14 00:31:24.157524 | 2025-11-14 00:31:24.157641 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-14 00:31:24.214118 | controller | skipping: Conditional result was False 2025-11-14 00:31:24.222602 | 2025-11-14 00:31:24.222721 | TASK [fetch-output : Set log path for single node] 2025-11-14 00:31:24.265326 | controller | ok 2025-11-14 00:31:24.272767 | 2025-11-14 00:31:24.272859 | LOOP [fetch-output : Ensure local output dirs] 2025-11-14 00:31:24.718017 | controller -> localhost | ok: "/var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/logs" 2025-11-14 00:31:25.031038 | controller -> localhost | changed: "/var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/artifacts" 2025-11-14 00:31:25.325071 | controller -> localhost | changed: "/var/lib/zuul/builds/8a01cf186a614fe882d1aa912de5fd0b/work/docs" 2025-11-14 00:31:25.338962 | 2025-11-14 00:31:25.339075 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-14 00:31:26.076739 | controller | changed: 2025-11-14 00:31:26.077081 | controller | .d..t...... ./ 2025-11-14 00:31:26.077142 | controller | cd+++++++++ controller/ 2025-11-14 00:31:26.077211 | controller | changed: All items complete 2025-11-14 00:31:26.077257 | 2025-11-14 00:31:26.562053 | controller | changed: .d..t...... ./ 2025-11-14 00:31:27.129784 | controller | changed: .d..t...... ./ 2025-11-14 00:31:27.166868 | 2025-11-14 00:31:27.167111 | TASK [include_role : fetch-output-openshift] 2025-11-14 00:31:27.193182 | controller | skipping: Conditional result was False 2025-11-14 00:31:27.203635 | 2025-11-14 00:31:27.203809 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-14 00:31:27.251843 | controller | skipping: Conditional result was False 2025-11-14 00:31:27.265957 | controller | skipping: Conditional result was False 2025-11-14 00:31:27.323388 | 2025-11-14 00:31:27.323525 | PLAY [localhost] 2025-11-14 00:31:27.342241 | 2025-11-14 00:31:27.342390 | TASK [Run Zuul manifest role] 2025-11-14 00:31:27.365043 | localhost | ok 2025-11-14 00:31:27.386113 | 2025-11-14 00:31:27.386239 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-14 00:31:27.823533 | localhost | changed 2025-11-14 00:31:27.828307 | 2025-11-14 00:31:27.828370 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-14 00:31:27.857339 | localhost | ok 2025-11-14 00:31:27.866881 | 2025-11-14 00:31:27.866995 | TASK [Set zuul-log-path fact] 2025-11-14 00:31:27.887163 | localhost | ok 2025-11-14 00:31:27.901765 | 2025-11-14 00:31:27.901862 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-14 00:31:27.943060 | localhost | ok 2025-11-14 00:31:27.955180 | 2025-11-14 00:31:27.955323 | LOOP [Run upload-logs-swift role] 2025-11-14 00:31:28.002071 | localhost | Output suppressed because no_log was given 2025-11-14 00:31:28.027201 | 2025-11-14 00:31:28.027312 | TASK [Set zuul-log-path fact] 2025-11-14 00:31:28.061955 | localhost | skipping: Conditional result was False 2025-11-14 00:31:28.069915 | 2025-11-14 00:31:28.070008 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-14 00:31:28.543732 | localhost -> localhost | ok: Runtime: 0:00:00.009162 2025-11-14 00:31:28.599261 | 2025-11-14 00:31:28.599448 | TASK [upload-logs-swift : Upload logs to swift]