2025-12-15 00:06:49.501746 | Job console starting... 2025-12-15 00:06:49.511917 | Updating repositories 2025-12-15 00:06:50.146610 | Preparing job workspace 2025-12-15 00:06:57.343299 | Running Ansible setup... 2025-12-15 00:07:01.985209 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-15 00:07:02.680934 | 2025-12-15 00:07:02.681075 | PLAY [localhost] 2025-12-15 00:07:02.690388 | 2025-12-15 00:07:02.690495 | TASK [Gathering Facts] 2025-12-15 00:07:03.702314 | localhost | ok 2025-12-15 00:07:03.729220 | 2025-12-15 00:07:03.729372 | TASK [Setup log path fact] 2025-12-15 00:07:03.751526 | localhost | ok 2025-12-15 00:07:03.775522 | 2025-12-15 00:07:03.775710 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-15 00:07:03.807703 | localhost | ok 2025-12-15 00:07:03.821307 | 2025-12-15 00:07:03.821459 | TASK [emit-job-header : Print job information] 2025-12-15 00:07:03.865535 | # Job Information 2025-12-15 00:07:03.865849 | Ansible Version: 2.15.12 2025-12-15 00:07:03.865914 | Job: ansible-test-sanity-docker-devel 2025-12-15 00:07:03.865953 | Pipeline: periodic 2025-12-15 00:07:03.865988 | Executor: ze04.softwarefactory-project.io 2025-12-15 00:07:03.866023 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-15 00:07:03.866064 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/02c/ansible/02c3ff9b10084a64a33bb2e0b1b62c7c/ 2025-12-15 00:07:03.866099 | Event ID: 4fcac70710aa4c2dbcb2a11ca9888703 2025-12-15 00:07:03.872722 | 2025-12-15 00:07:03.872830 | LOOP [emit-job-header : Print node information] 2025-12-15 00:07:04.002873 | localhost | ok: 2025-12-15 00:07:04.003121 | localhost | # Node Information 2025-12-15 00:07:04.003169 | localhost | Inventory Hostname: controller 2025-12-15 00:07:04.003207 | localhost | Hostname: np0005559291 2025-12-15 00:07:04.003241 | localhost | Username: zuul 2025-12-15 00:07:04.003276 | localhost | Distro: Fedora 37 2025-12-15 00:07:04.003304 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-15 00:07:04.003330 | localhost | Region: ca-ymq-1 2025-12-15 00:07:04.003355 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-15 00:07:04.003380 | localhost | Product Name: OpenStack Nova 2025-12-15 00:07:04.003406 | localhost | Interface IP: 162.253.55.209 2025-12-15 00:07:04.018285 | 2025-12-15 00:07:04.018400 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-15 00:07:04.440512 | localhost -> localhost | changed 2025-12-15 00:07:04.446340 | 2025-12-15 00:07:04.446420 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-15 00:07:05.276574 | localhost -> localhost | changed 2025-12-15 00:07:05.296024 | 2025-12-15 00:07:05.296089 | PLAY [all:!appliance*] 2025-12-15 00:07:05.343101 | 2025-12-15 00:07:05.343239 | TASK [include_role : start-zuul-console] 2025-12-15 00:07:05.361791 | controller | ok 2025-12-15 00:07:05.376248 | 2025-12-15 00:07:05.376338 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-15 00:07:05.921626 | controller | ok 2025-12-15 00:07:05.933841 | 2025-12-15 00:07:05.933933 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-15 00:07:28.649898 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-15 00:07:28.660393 | 2025-12-15 00:07:28.660723 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-15 00:07:29.205470 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.213769 | 2025-12-15 00:07:29.213878 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-15 00:07:29.239849 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.250713 | 2025-12-15 00:07:29.250819 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-15 00:07:29.275910 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.286376 | 2025-12-15 00:07:29.286654 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-15 00:07:29.321968 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.330987 | 2025-12-15 00:07:29.331091 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-15 00:07:29.356108 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.367526 | 2025-12-15 00:07:29.367703 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-15 00:07:29.392798 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.409112 | 2025-12-15 00:07:29.409226 | TASK [Disable Fedora Modular] 2025-12-15 00:07:29.832281 | controller | changed 2025-12-15 00:07:29.841002 | 2025-12-15 00:07:29.841129 | TASK [Enable EPEL] 2025-12-15 00:07:29.866306 | controller | skipping: Conditional result was False 2025-12-15 00:07:29.881315 | 2025-12-15 00:07:29.881506 | TASK [Register the RHEL node] 2025-12-15 00:07:30.439311 | 2025-12-15 00:07:30.439506 | TASK [Show the subscription-manager status] 2025-12-15 00:07:30.992309 | controller | skipping: Conditional result was False 2025-12-15 00:07:30.999510 | 2025-12-15 00:07:30.999618 | TASK [Enable EPEL on RHEL] 2025-12-15 00:07:31.549738 | controller | skipping: Conditional result was False 2025-12-15 00:07:31.556586 | 2025-12-15 00:07:31.556666 | TASK [Install git and tox] 2025-12-15 00:08:32.629468 | controller | changed 2025-12-15 00:08:32.646490 | 2025-12-15 00:08:32.646740 | TASK [include_role : prepare-workspace] 2025-12-15 00:08:32.689566 | controller | ok 2025-12-15 00:08:32.726165 | 2025-12-15 00:08:32.726295 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-15 00:08:32.987994 | controller | ok 2025-12-15 00:08:33.003645 | 2025-12-15 00:08:33.003829 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-15 00:08:45.466621 | controller | Output suppressed because no_log was given 2025-12-15 00:08:45.477950 | 2025-12-15 00:08:45.478087 | TASK [include_role : prepare-workspace-openshift] 2025-12-15 00:08:45.495268 | controller | skipping: Conditional result was False 2025-12-15 00:08:45.519213 | 2025-12-15 00:08:45.519291 | PLAY [all:!appliance] 2025-12-15 00:08:45.536498 | 2025-12-15 00:08:45.536569 | TASK [Run add-build-sshkey role (RSA)] 2025-12-15 00:08:45.556525 | controller | ok 2025-12-15 00:08:45.571512 | 2025-12-15 00:08:45.571611 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-15 00:08:45.788937 | controller -> localhost | ok 2025-12-15 00:08:45.796088 | 2025-12-15 00:08:45.796169 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-15 00:08:45.818650 | controller | ok 2025-12-15 00:08:45.833663 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-15 00:08:45.839987 | 2025-12-15 00:08:45.840051 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-15 00:08:46.327414 | controller -> localhost | Generating public/private rsa key pair. 2025-12-15 00:08:46.327627 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_rsa. 2025-12-15 00:08:46.327660 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_rsa.pub. 2025-12-15 00:08:46.327893 | controller -> localhost | The key fingerprint is: 2025-12-15 00:08:46.327928 | controller -> localhost | SHA256:UsqwDMgV3P508OzzwJkxqKZpWM6okXwUSXrKpDkkd/0 zuul-build-sshkey 2025-12-15 00:08:46.327951 | controller -> localhost | The key's randomart image is: 2025-12-15 00:08:46.327972 | controller -> localhost | +---[RSA 2048]----+ 2025-12-15 00:08:46.327992 | controller -> localhost | | .+o | 2025-12-15 00:08:46.328012 | controller -> localhost | |..+..o . | 2025-12-15 00:08:46.328033 | controller -> localhost | |o=o++ . * | 2025-12-15 00:08:46.328053 | controller -> localhost | |*oo+.= * * | 2025-12-15 00:08:46.328072 | controller -> localhost | |+o .o B E = | 2025-12-15 00:08:46.328101 | controller -> localhost | |.o.. o o B | 2025-12-15 00:08:46.328127 | controller -> localhost | |o.*.+ + | 2025-12-15 00:08:46.328150 | controller -> localhost | | +.* . | 2025-12-15 00:08:46.328171 | controller -> localhost | |o . | 2025-12-15 00:08:46.328193 | controller -> localhost | +----[SHA256]-----+ 2025-12-15 00:08:46.328243 | controller -> localhost | ok: Runtime: 0:00:00.029321 2025-12-15 00:08:46.335866 | 2025-12-15 00:08:46.335984 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-15 00:08:46.367842 | controller | ok 2025-12-15 00:08:46.380674 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-15 00:08:46.392110 | 2025-12-15 00:08:46.392218 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-15 00:08:46.416617 | controller | skipping: Conditional result was False 2025-12-15 00:08:46.423652 | 2025-12-15 00:08:46.423765 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-15 00:08:46.893163 | controller | changed 2025-12-15 00:08:46.899005 | 2025-12-15 00:08:46.899074 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-15 00:08:47.114515 | controller | ok 2025-12-15 00:08:47.134186 | 2025-12-15 00:08:47.134346 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-15 00:08:47.770312 | controller | changed 2025-12-15 00:08:47.779793 | 2025-12-15 00:08:47.779940 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-15 00:08:48.408032 | controller | changed 2025-12-15 00:08:48.417102 | 2025-12-15 00:08:48.417196 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-15 00:08:48.443226 | controller | skipping: Conditional result was False 2025-12-15 00:08:48.453564 | 2025-12-15 00:08:48.453664 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-15 00:08:48.856950 | controller -> localhost | changed 2025-12-15 00:08:48.869047 | 2025-12-15 00:08:48.869166 | TASK [add-build-sshkey : Add back temp key] 2025-12-15 00:08:49.179151 | controller -> localhost | Identity added: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_rsa (zuul-build-sshkey) 2025-12-15 00:08:49.179466 | controller -> localhost | ok: Runtime: 0:00:00.007704 2025-12-15 00:08:49.187361 | 2025-12-15 00:08:49.187427 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-15 00:08:49.518431 | controller | ok 2025-12-15 00:08:49.525420 | 2025-12-15 00:08:49.525489 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-15 00:08:49.584851 | controller | skipping: Conditional result was False 2025-12-15 00:08:49.602163 | 2025-12-15 00:08:49.602275 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-15 00:08:49.637277 | controller | ok 2025-12-15 00:08:49.662911 | 2025-12-15 00:08:49.663046 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-15 00:08:49.932937 | controller -> localhost | ok 2025-12-15 00:08:49.940854 | 2025-12-15 00:08:49.940970 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-15 00:08:49.969644 | controller | ok 2025-12-15 00:08:49.984500 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-15 00:08:49.991018 | 2025-12-15 00:08:49.991080 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-15 00:08:50.291075 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-15 00:08:50.291299 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_ecdsa. 2025-12-15 00:08:50.291328 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_ecdsa.pub. 2025-12-15 00:08:50.291358 | controller -> localhost | The key fingerprint is: 2025-12-15 00:08:50.291380 | controller -> localhost | SHA256:qQQzwsXXZ1EzbOnUAlWryL3rvmXIDeug4vCDe9Preug zuul-build-sshkey 2025-12-15 00:08:50.291399 | controller -> localhost | The key's randomart image is: 2025-12-15 00:08:50.291418 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-15 00:08:50.291435 | controller -> localhost | | .. . o*=+. | 2025-12-15 00:08:50.291453 | controller -> localhost | | . .. . . o *o.. | 2025-12-15 00:08:50.291470 | controller -> localhost | | o +. o + .. | 2025-12-15 00:08:50.291488 | controller -> localhost | | . + o o.. | 2025-12-15 00:08:50.291507 | controller -> localhost | | . S o + | 2025-12-15 00:08:50.291527 | controller -> localhost | | . . . * | 2025-12-15 00:08:50.291544 | controller -> localhost | | ...o . = + | 2025-12-15 00:08:50.291560 | controller -> localhost | | .o* o. o + | 2025-12-15 00:08:50.291577 | controller -> localhost | | .=EB+. o*. | 2025-12-15 00:08:50.291598 | controller -> localhost | +----[SHA256]-----+ 2025-12-15 00:08:50.291648 | controller -> localhost | ok: Runtime: 0:00:00.009676 2025-12-15 00:08:50.299444 | 2025-12-15 00:08:50.299510 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-15 00:08:50.355362 | controller | ok 2025-12-15 00:08:50.366008 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-15 00:08:50.376923 | 2025-12-15 00:08:50.376988 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-15 00:08:50.401148 | controller | skipping: Conditional result was False 2025-12-15 00:08:50.407811 | 2025-12-15 00:08:50.407880 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-15 00:08:50.684141 | controller | changed 2025-12-15 00:08:50.701344 | 2025-12-15 00:08:50.701559 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-15 00:08:50.927724 | controller | ok 2025-12-15 00:08:50.937611 | 2025-12-15 00:08:50.937816 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-15 00:08:51.634171 | controller | changed 2025-12-15 00:08:51.641316 | 2025-12-15 00:08:51.641400 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-15 00:08:52.302733 | controller | changed 2025-12-15 00:08:52.310472 | 2025-12-15 00:08:52.310850 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-15 00:08:52.340411 | controller | skipping: Conditional result was False 2025-12-15 00:08:52.357493 | 2025-12-15 00:08:52.357731 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-15 00:08:52.633126 | controller -> localhost | changed 2025-12-15 00:08:52.648785 | 2025-12-15 00:08:52.648959 | TASK [add-build-sshkey : Add back temp key] 2025-12-15 00:08:52.984928 | controller -> localhost | Identity added: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/02c3ff9b10084a64a33bb2e0b1b62c7c_id_ecdsa (zuul-build-sshkey) 2025-12-15 00:08:52.985300 | controller -> localhost | ok: Runtime: 0:00:00.015373 2025-12-15 00:08:52.993268 | 2025-12-15 00:08:52.993356 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-15 00:08:53.203565 | controller | ok 2025-12-15 00:08:53.209994 | 2025-12-15 00:08:53.210112 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-15 00:08:53.254710 | controller | skipping: Conditional result was False 2025-12-15 00:08:53.277699 | 2025-12-15 00:08:53.277856 | TASK [include_role : remove-zuul-sshkey] 2025-12-15 00:08:53.292878 | controller | skipping: Conditional result was False 2025-12-15 00:08:53.302002 | 2025-12-15 00:08:53.302106 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-15 00:08:53.533095 | controller | ok: "logs" 2025-12-15 00:08:53.533350 | controller | ok: All items complete 2025-12-15 00:08:53.533380 | 2025-12-15 00:08:53.717506 | controller | ok: "artifacts" 2025-12-15 00:08:53.903902 | controller | ok: "docs" 2025-12-15 00:08:53.917277 | 2025-12-15 00:08:53.917400 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-15 00:08:54.129477 | controller | changed: "logs" 2025-12-15 00:08:54.321599 | controller | changed: "artifacts" 2025-12-15 00:08:54.490468 | controller | changed: "docs" 2025-12-15 00:08:54.522500 | 2025-12-15 00:08:54.522596 | PLAY RECAP 2025-12-15 00:08:54.522638 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-15 00:08:54.522663 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-15 00:08:54.522703 | 2025-12-15 00:08:54.650962 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-15 00:08:54.653182 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-15 00:08:55.277590 | 2025-12-15 00:08:55.277743 | PLAY [all] 2025-12-15 00:08:55.300642 | 2025-12-15 00:08:55.300802 | TASK [Install binary dependencies] 2025-12-15 00:08:55.350615 | controller | ok 2025-12-15 00:08:55.372205 | 2025-12-15 00:08:55.372349 | TASK [bindep : Include find tasks] 2025-12-15 00:08:55.402244 | controller | ok 2025-12-15 00:08:55.410549 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-15 00:08:55.416843 | 2025-12-15 00:08:55.416905 | TASK [bindep : Look for bindep.txt] 2025-12-15 00:08:55.773102 | controller | ok 2025-12-15 00:08:55.779185 | 2025-12-15 00:08:55.779270 | TASK [bindep : Define bindep_file fact] 2025-12-15 00:08:55.806337 | controller | skipping: Conditional result was False 2025-12-15 00:08:55.815196 | 2025-12-15 00:08:55.815281 | TASK [bindep : Look for other-requirements.txt] 2025-12-15 00:08:56.042517 | controller | ok 2025-12-15 00:08:56.050608 | 2025-12-15 00:08:56.051064 | TASK [bindep : Define bindep_file fact] 2025-12-15 00:08:56.077514 | controller | skipping: Conditional result was False 2025-12-15 00:08:56.088086 | 2025-12-15 00:08:56.088210 | TASK [bindep : Look for bindep fallback file] 2025-12-15 00:08:56.113716 | controller | skipping: Conditional result was False 2025-12-15 00:08:56.121040 | 2025-12-15 00:08:56.121122 | TASK [bindep : Define bindep_file fact] 2025-12-15 00:08:56.146280 | controller | skipping: Conditional result was False 2025-12-15 00:08:56.153430 | 2025-12-15 00:08:56.153529 | TASK [bindep : Include bindep tasks] 2025-12-15 00:08:56.182371 | controller | skipping: Conditional result was False 2025-12-15 00:08:56.189270 | 2025-12-15 00:08:56.189366 | TASK [bindep : Include install tasks] 2025-12-15 00:08:56.213374 | controller | skipping: Conditional result was False 2025-12-15 00:08:56.220202 | 2025-12-15 00:08:56.220303 | LOOP [bindep : Include package tasks] 2025-12-15 00:08:56.286323 | 2025-12-15 00:08:56.286484 | TASK [Run test-setup role] 2025-12-15 00:08:56.306913 | controller | ok 2025-12-15 00:08:56.331786 | 2025-12-15 00:08:56.331911 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-15 00:08:56.540080 | controller | ok 2025-12-15 00:08:56.546824 | 2025-12-15 00:08:56.546960 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-15 00:08:57.082366 | controller | skipping: Conditional result was False 2025-12-15 00:08:57.135206 | 2025-12-15 00:08:57.135362 | PLAY RECAP 2025-12-15 00:08:57.135446 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-15 00:08:57.135491 | 2025-12-15 00:08:57.268154 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-15 00:08:57.269132 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-15 00:08:57.886830 | 2025-12-15 00:08:57.886963 | PLAY [controller] 2025-12-15 00:08:57.910778 | 2025-12-15 00:08:57.910923 | TASK [Create the /root directory] 2025-12-15 00:08:58.319220 | controller | ok 2025-12-15 00:08:58.327283 | 2025-12-15 00:08:58.327411 | TASK [Install glibc-langpack-en] 2025-12-15 00:09:02.407039 | controller | ok: Nothing to do 2025-12-15 00:09:02.413588 | 2025-12-15 00:09:02.413668 | TASK [Ensure controller directory exists] 2025-12-15 00:09:02.625856 | controller | changed 2025-12-15 00:09:02.639866 | 2025-12-15 00:09:02.640007 | TASK [Install container runtime] 2025-12-15 00:09:02.695831 | controller | ok 2025-12-15 00:09:02.733964 | 2025-12-15 00:09:02.734097 | LOOP [ensure-podman : Find distribution installation] 2025-12-15 00:09:02.760797 | controller | ok: "/var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-15 00:09:02.779312 | controller | included: /var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-15 00:09:02.791266 | 2025-12-15 00:09:02.791417 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-15 00:10:10.571127 | controller | changed 2025-12-15 00:10:10.580422 | 2025-12-15 00:10:10.580531 | TASK [ensure-podman : Fetch podman version] 2025-12-15 00:10:11.162517 | controller | Client: Podman Engine 2025-12-15 00:10:11.162682 | controller | Version: 4.6.2 2025-12-15 00:10:11.162754 | controller | API Version: 4.6.2 2025-12-15 00:10:11.162820 | controller | Go Version: go1.19.12 2025-12-15 00:10:11.162897 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-15 00:10:11.162966 | controller | OS/Arch: linux/amd64 2025-12-15 00:10:11.623767 | controller | ok: Runtime: 0:00:00.204286 2025-12-15 00:10:11.637185 | 2025-12-15 00:10:11.637330 | TASK [ensure-podman : Print podman version installed] 2025-12-15 00:10:11.676894 | Podman version: Client: Podman Engine 2025-12-15 00:10:11.677136 | Version: 4.6.2 2025-12-15 00:10:11.677201 | API Version: 4.6.2 2025-12-15 00:10:11.677249 | Go Version: go1.19.12 2025-12-15 00:10:11.677291 | Built: Mon Aug 28 19:38:31 2023 2025-12-15 00:10:11.677334 | OS/Arch: linux/amd64 2025-12-15 00:10:11.691099 | 2025-12-15 00:10:11.691236 | TASK [ensure-podman : Validate podman engine] 2025-12-15 00:10:12.236557 | controller | skipping: Conditional result was False 2025-12-15 00:10:12.243162 | 2025-12-15 00:10:12.243241 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-15 00:10:12.257121 | controller | skipping: Conditional result was False 2025-12-15 00:10:12.270250 | 2025-12-15 00:10:12.270330 | TASK [Ensure python3.8 is present] 2025-12-15 00:10:12.295699 | controller | skipping: Conditional result was False 2025-12-15 00:10:12.305875 | 2025-12-15 00:10:12.305992 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-15 00:10:12.339098 | controller | ok 2025-12-15 00:10:12.362790 | 2025-12-15 00:10:12.362880 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-15 00:10:13.767608 | controller | ok: Nothing to do 2025-12-15 00:10:13.774319 | 2025-12-15 00:10:13.774386 | TASK [our-ensure-python : Also install python3-devel] 2025-12-15 00:10:25.232692 | controller | changed 2025-12-15 00:10:25.245349 | 2025-12-15 00:10:25.245462 | TASK [Run ensure-virtualenv role] 2025-12-15 00:10:25.267042 | controller | ok 2025-12-15 00:10:25.293165 | 2025-12-15 00:10:25.293279 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-15 00:10:25.552176 | controller | /usr/bin/virtualenv 2025-12-15 00:10:25.871286 | controller | ok: Runtime: 0:00:00.004299 2025-12-15 00:10:25.880313 | 2025-12-15 00:10:25.880449 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-15 00:10:25.916964 | controller | skipping: Conditional result was False 2025-12-15 00:10:25.917237 | controller | ok: All items complete 2025-12-15 00:10:25.917270 | 2025-12-15 00:10:25.944513 | 2025-12-15 00:10:25.944701 | TASK [Find the full path of the Python interpreter] 2025-12-15 00:10:26.194149 | controller | /usr/bin/python3 2025-12-15 00:10:26.494937 | controller | ok 2025-12-15 00:10:26.501563 | 2025-12-15 00:10:26.501661 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-15 00:10:27.354704 | controller | created virtual environment CPython3.11.0.final.0-64 in 456ms 2025-12-15 00:10:27.372779 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-15 00:10:27.372817 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2025-12-15 00:10:27.372826 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-15 00:10:27.372840 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-15 00:10:27.541750 | controller | changed 2025-12-15 00:10:27.566107 | 2025-12-15 00:10:27.566243 | TASK [Set selinux package] 2025-12-15 00:10:27.600725 | controller | ok 2025-12-15 00:10:27.613927 | 2025-12-15 00:10:27.614045 | TASK [Set selinux package (Fedora)] 2025-12-15 00:10:27.644254 | controller | ok 2025-12-15 00:10:27.649479 | 2025-12-15 00:10:27.649568 | TASK [Install selinux into virtualenv] 2025-12-15 00:11:28.903157 | controller | Collecting selinux-please-lie-to-me 2025-12-15 00:11:41.287264 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-15 00:11:41.597488 | controller | Collecting setuptools<50.0.0 2025-12-15 00:11:41.603256 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-15 00:11:41.644643 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.3 MB/s eta 0:00:00 2025-12-15 00:11:41.725891 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-15 00:11:41.726137 | controller | Attempting uninstall: setuptools 2025-12-15 00:11:41.728639 | controller | Found existing installation: setuptools 62.6.0 2025-12-15 00:11:41.787656 | controller | Uninstalling setuptools-62.6.0: 2025-12-15 00:11:41.795556 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-15 00:11:42.151957 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-15 00:11:53.616550 | controller | 2025-12-15 00:11:53.723856 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-15 00:11:53.723897 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-15 00:11:53.753309 | controller | ok: Runtime: 0:01:25.861844 2025-12-15 00:11:53.759202 | 2025-12-15 00:11:53.759267 | TASK [Install pytest-forked into virtualenv] 2025-12-15 00:12:06.678506 | controller | Collecting pytest-forked 2025-12-15 00:12:42.778938 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-15 00:12:42.828408 | controller | Collecting py 2025-12-15 00:12:42.839539 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-15 00:12:42.855683 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.8 MB/s eta 0:00:00 2025-12-15 00:12:42.967825 | controller | Collecting pytest>=3.10 2025-12-15 00:12:42.977692 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-15 00:12:42.998048 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.3 MB/s eta 0:00:00 2025-12-15 00:12:43.033360 | controller | Collecting iniconfig>=1.0.1 2025-12-15 00:12:43.037174 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-15 00:12:43.084299 | controller | Collecting packaging>=22 2025-12-15 00:12:43.088561 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-15 00:12:43.096636 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.7 MB/s eta 0:00:00 2025-12-15 00:12:43.128458 | controller | Collecting pluggy<2,>=1.5 2025-12-15 00:12:43.132640 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-15 00:12:43.185763 | controller | Collecting pygments>=2.7.2 2025-12-15 00:12:43.189807 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-15 00:12:43.216046 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 60.2 MB/s eta 0:00:00 2025-12-15 00:12:43.282656 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-15 00:12:44.352862 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2025-12-15 00:12:44.361621 | controller | 2025-12-15 00:12:44.430506 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-15 00:12:44.430612 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-15 00:12:44.817980 | controller | ok: Runtime: 0:00:50.471926 2025-12-15 00:12:44.824170 | 2025-12-15 00:12:44.824244 | TASK [Update pip] 2025-12-15 00:12:45.333710 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-15 00:12:57.754244 | controller | Collecting pip 2025-12-15 00:13:09.948702 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-15 00:13:10.006822 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.2 MB/s eta 0:00:00 2025-12-15 00:13:10.086121 | controller | Installing collected packages: pip 2025-12-15 00:13:10.086363 | controller | Attempting uninstall: pip 2025-12-15 00:13:10.088552 | controller | Found existing installation: pip 22.2.2 2025-12-15 00:13:10.228223 | controller | Uninstalling pip-22.2.2: 2025-12-15 00:13:10.243107 | controller | Successfully uninstalled pip-22.2.2 2025-12-15 00:13:11.063355 | controller | Successfully installed pip-25.3 2025-12-15 00:13:11.370001 | controller | ok: Runtime: 0:00:26.097685 2025-12-15 00:13:11.380201 | 2025-12-15 00:13:11.380471 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-15 00:13:11.589292 | controller | changed 2025-12-15 00:13:11.654619 | 2025-12-15 00:13:11.654835 | TASK [Install ansible into virtualenv] 2025-12-15 00:13:12.126684 | controller | Processing ./src/github.com/ansible/ansible 2025-12-15 00:13:12.129810 | controller | Installing build dependencies: started 2025-12-15 00:13:35.099407 | controller | Installing build dependencies: finished with status 'done' 2025-12-15 00:13:35.099998 | controller | Getting requirements to build wheel: started 2025-12-15 00:13:35.846174 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-15 00:13:35.847016 | controller | Preparing metadata (pyproject.toml): started 2025-12-15 00:13:36.326996 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-15 00:13:36.332440 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2025-12-15 00:13:36.336001 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-15 00:13:36.699757 | controller | ERROR 2025-12-15 00:13:36.699934 | controller | { 2025-12-15 00:13:36.699975 | controller | "delta": "0:00:24.546337", 2025-12-15 00:13:36.700029 | controller | "end": "2025-12-15 00:13:36.398575", 2025-12-15 00:13:36.700068 | controller | "msg": "non-zero return code", 2025-12-15 00:13:36.700107 | controller | "rc": 1, 2025-12-15 00:13:36.700130 | controller | "start": "2025-12-15 00:13:11.852238" 2025-12-15 00:13:36.700152 | controller | } failure 2025-12-15 00:13:36.702445 | 2025-12-15 00:13:36.702513 | PLAY RECAP 2025-12-15 00:13:36.702570 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-15 00:13:36.702599 | 2025-12-15 00:13:36.849551 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-15 00:13:36.850700 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-15 00:13:37.455006 | 2025-12-15 00:13:37.455208 | PLAY [all] 2025-12-15 00:13:37.481447 | 2025-12-15 00:13:37.481690 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-15 00:13:37.727600 | controller | changed: non-zero return code 2025-12-15 00:13:37.733581 | 2025-12-15 00:13:37.733662 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-15 00:13:37.760620 | controller | skipping: Conditional result was False 2025-12-15 00:13:37.770237 | 2025-12-15 00:13:37.770380 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-15 00:13:37.806608 | 2025-12-15 00:13:37.806886 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-15 00:13:37.841942 | 2025-12-15 00:13:37.842163 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-15 00:13:37.857628 | controller | skipping: Conditional result was False 2025-12-15 00:13:37.868405 | 2025-12-15 00:13:37.868559 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-15 00:13:37.903088 | 2025-12-15 00:13:37.903300 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-15 00:13:37.928827 | controller | skipping: Conditional result was False 2025-12-15 00:13:37.937553 | 2025-12-15 00:13:37.937654 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-15 00:13:37.963198 | controller | skipping: Conditional result was False 2025-12-15 00:13:37.969664 | 2025-12-15 00:13:37.969761 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-15 00:13:37.984078 | controller | skipping: Conditional result was False 2025-12-15 00:13:38.011995 | 2025-12-15 00:13:38.012091 | PLAY RECAP 2025-12-15 00:13:38.012138 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-15 00:13:38.012159 | 2025-12-15 00:13:38.117429 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-15 00:13:38.118388 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-15 00:13:38.735496 | 2025-12-15 00:13:38.735618 | PLAY [all:!appliance*] 2025-12-15 00:13:38.779944 | 2025-12-15 00:13:38.780088 | TASK [unregister the node] 2025-12-15 00:13:39.315241 | controller | skipping: Conditional result was False 2025-12-15 00:13:39.321517 | 2025-12-15 00:13:39.321596 | TASK [include_role : fetch-output] 2025-12-15 00:13:39.353419 | controller | ok 2025-12-15 00:13:39.387598 | 2025-12-15 00:13:39.387811 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-15 00:13:39.443478 | controller | skipping: Conditional result was False 2025-12-15 00:13:39.452594 | 2025-12-15 00:13:39.452741 | TASK [fetch-output : Set log path for single node] 2025-12-15 00:13:39.495655 | controller | ok 2025-12-15 00:13:39.505033 | 2025-12-15 00:13:39.505173 | LOOP [fetch-output : Ensure local output dirs] 2025-12-15 00:13:39.963859 | controller -> localhost | ok: "/var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/logs" 2025-12-15 00:13:40.202976 | controller -> localhost | changed: "/var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/artifacts" 2025-12-15 00:13:40.429794 | controller -> localhost | changed: "/var/lib/zuul/builds/02c3ff9b10084a64a33bb2e0b1b62c7c/work/docs" 2025-12-15 00:13:40.440319 | 2025-12-15 00:13:40.440417 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-15 00:13:41.076454 | controller | changed: 2025-12-15 00:13:41.076952 | controller | .d..t...... ./ 2025-12-15 00:13:41.077014 | controller | cd+++++++++ controller/ 2025-12-15 00:13:41.077178 | controller | changed: All items complete 2025-12-15 00:13:41.077223 | 2025-12-15 00:13:41.526109 | controller | changed: .d..t...... ./ 2025-12-15 00:13:41.987376 | controller | changed: .d..t...... ./ 2025-12-15 00:13:42.006670 | 2025-12-15 00:13:42.006848 | TASK [include_role : fetch-output-openshift] 2025-12-15 00:13:42.033289 | controller | skipping: Conditional result was False 2025-12-15 00:13:42.042451 | 2025-12-15 00:13:42.042573 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-15 00:13:42.090106 | controller | skipping: Conditional result was False 2025-12-15 00:13:42.090837 | controller | skipping: Conditional result was False 2025-12-15 00:13:42.123626 | 2025-12-15 00:13:42.123755 | PLAY [localhost] 2025-12-15 00:13:42.135933 | 2025-12-15 00:13:42.136005 | TASK [Run Zuul manifest role] 2025-12-15 00:13:42.154708 | localhost | ok 2025-12-15 00:13:42.169358 | 2025-12-15 00:13:42.169486 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-15 00:13:42.555936 | localhost | changed 2025-12-15 00:13:42.560850 | 2025-12-15 00:13:42.560934 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-15 00:13:42.592052 | localhost | ok 2025-12-15 00:13:42.608452 | 2025-12-15 00:13:42.608552 | TASK [Set zuul-log-path fact] 2025-12-15 00:13:42.626359 | localhost | ok 2025-12-15 00:13:42.639744 | 2025-12-15 00:13:42.639852 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-15 00:13:42.681452 | localhost | ok 2025-12-15 00:13:42.689734 | 2025-12-15 00:13:42.689850 | LOOP [Run upload-logs-swift role] 2025-12-15 00:13:42.724289 | localhost | Output suppressed because no_log was given 2025-12-15 00:13:42.747980 | 2025-12-15 00:13:42.748070 | TASK [Set zuul-log-path fact] 2025-12-15 00:13:42.772157 | localhost | skipping: Conditional result was False 2025-12-15 00:13:42.776955 | 2025-12-15 00:13:42.777021 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-15 00:13:43.211451 | localhost -> localhost | ok: Runtime: 0:00:00.013814 2025-12-15 00:13:43.219953 | 2025-12-15 00:13:43.220076 | TASK [upload-logs-swift : Upload logs to swift]