2026-02-03 00:06:40.802253 | Job console starting... 2026-02-03 00:06:40.813946 | Updating repositories 2026-02-03 00:06:42.369996 | Preparing job workspace 2026-02-03 00:06:46.851036 | Running Ansible setup... 2026-02-03 00:06:51.967883 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-03 00:06:52.791905 | 2026-02-03 00:06:52.792045 | PLAY [localhost] 2026-02-03 00:06:52.811777 | 2026-02-03 00:06:52.811899 | TASK [Gathering Facts] 2026-02-03 00:06:53.892924 | localhost | ok 2026-02-03 00:06:53.912595 | 2026-02-03 00:06:53.912793 | TASK [Setup log path fact] 2026-02-03 00:06:53.934193 | localhost | ok 2026-02-03 00:06:53.953591 | 2026-02-03 00:06:53.953761 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 00:06:53.984906 | localhost | ok 2026-02-03 00:06:53.994022 | 2026-02-03 00:06:53.994152 | TASK [emit-job-header : Print job information] 2026-02-03 00:06:54.043698 | # Job Information 2026-02-03 00:06:54.043846 | Ansible Version: 2.15.12 2026-02-03 00:06:54.043879 | Job: ansible-test-sanity-docker-devel 2026-02-03 00:06:54.043902 | Pipeline: periodic 2026-02-03 00:06:54.043923 | Executor: ze02.softwarefactory-project.io 2026-02-03 00:06:54.043944 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-03 00:06:54.043965 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a89/ansible/a890feadad7f4b529bd14c74d5ff7259/ 2026-02-03 00:06:54.043985 | Event ID: bc917e7b12a94a929f4345acdd6e8cbb 2026-02-03 00:06:54.047878 | 2026-02-03 00:06:54.047956 | LOOP [emit-job-header : Print node information] 2026-02-03 00:06:54.192132 | localhost | ok: 2026-02-03 00:06:54.192309 | localhost | # Node Information 2026-02-03 00:06:54.192349 | localhost | Inventory Hostname: controller 2026-02-03 00:06:54.192377 | localhost | Hostname: np0005606077 2026-02-03 00:06:54.192402 | localhost | Username: zuul 2026-02-03 00:06:54.192794 | localhost | Distro: Fedora 37 2026-02-03 00:06:54.192849 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-03 00:06:54.192882 | localhost | Region: ca-ymq-1 2026-02-03 00:06:54.192912 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-03 00:06:54.192939 | localhost | Product Name: OpenStack Nova 2026-02-03 00:06:54.192970 | localhost | Interface IP: 162.253.55.140 2026-02-03 00:06:54.213231 | 2026-02-03 00:06:54.213386 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-03 00:06:54.739342 | localhost -> localhost | changed 2026-02-03 00:06:54.744654 | 2026-02-03 00:06:54.744761 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-03 00:06:55.942257 | localhost -> localhost | changed 2026-02-03 00:06:55.965653 | 2026-02-03 00:06:55.965770 | PLAY [all:!appliance*] 2026-02-03 00:06:55.988461 | 2026-02-03 00:06:55.988585 | TASK [include_role : start-zuul-console] 2026-02-03 00:06:56.030099 | controller | ok 2026-02-03 00:06:56.044455 | 2026-02-03 00:06:56.044570 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-03 00:06:56.503124 | controller | ok 2026-02-03 00:06:56.528343 | 2026-02-03 00:06:56.528708 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-03 00:06:57.389833 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-03 00:06:57.407287 | 2026-02-03 00:06:57.407403 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-03 00:06:57.960830 | controller | skipping: Conditional result was False 2026-02-03 00:06:57.970604 | 2026-02-03 00:06:57.970718 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-03 00:06:57.996298 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.005183 | 2026-02-03 00:06:58.005303 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-03 00:06:58.031052 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.039689 | 2026-02-03 00:06:58.039779 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-03 00:06:58.063856 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.072831 | 2026-02-03 00:06:58.072922 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-03 00:06:58.097859 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.107767 | 2026-02-03 00:06:58.107856 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-03 00:06:58.132944 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.154613 | 2026-02-03 00:06:58.154779 | TASK [Disable Fedora Modular] 2026-02-03 00:06:58.409000 | controller | changed 2026-02-03 00:06:58.422566 | 2026-02-03 00:06:58.423541 | TASK [Enable EPEL] 2026-02-03 00:06:58.440962 | controller | skipping: Conditional result was False 2026-02-03 00:06:58.454999 | 2026-02-03 00:06:58.455151 | TASK [Register the RHEL node] 2026-02-03 00:06:59.012869 | 2026-02-03 00:06:59.013030 | TASK [Show the subscription-manager status] 2026-02-03 00:06:59.577960 | controller | skipping: Conditional result was False 2026-02-03 00:06:59.585083 | 2026-02-03 00:06:59.585197 | TASK [Enable EPEL on RHEL] 2026-02-03 00:07:00.119112 | controller | skipping: Conditional result was False 2026-02-03 00:07:00.128354 | 2026-02-03 00:07:00.128490 | TASK [Install git and tox] 2026-02-03 00:08:31.268477 | controller | changed 2026-02-03 00:08:31.278557 | 2026-02-03 00:08:31.278709 | TASK [include_role : prepare-workspace] 2026-02-03 00:08:31.325962 | controller | ok 2026-02-03 00:08:31.378025 | 2026-02-03 00:08:31.378210 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-03 00:08:31.647219 | controller | ok 2026-02-03 00:08:31.663203 | 2026-02-03 00:08:31.663319 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-03 00:14:25.511636 | controller | Output suppressed because no_log was given 2026-02-03 00:14:25.523119 | 2026-02-03 00:14:25.523195 | TASK [include_role : prepare-workspace-openshift] 2026-02-03 00:14:25.552343 | controller | skipping: Conditional result was False 2026-02-03 00:14:25.588911 | 2026-02-03 00:14:25.589021 | PLAY [all:!appliance] 2026-02-03 00:14:25.611640 | 2026-02-03 00:14:25.611754 | TASK [Run add-build-sshkey role (RSA)] 2026-02-03 00:14:25.642249 | controller | ok 2026-02-03 00:14:25.658628 | 2026-02-03 00:14:25.658739 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-03 00:14:25.958165 | controller -> localhost | ok 2026-02-03 00:14:25.965750 | 2026-02-03 00:14:25.965828 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-03 00:14:25.995758 | controller | ok 2026-02-03 00:14:26.017856 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-03 00:14:26.024234 | 2026-02-03 00:14:26.024311 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-03 00:14:26.515315 | controller -> localhost | Generating public/private rsa key pair. 2026-02-03 00:14:26.515579 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_rsa. 2026-02-03 00:14:26.515629 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_rsa.pub. 2026-02-03 00:14:26.515660 | controller -> localhost | The key fingerprint is: 2026-02-03 00:14:26.515723 | controller -> localhost | SHA256:NqxABF6DH0dCTgDMMJlgMhIOgVf7yXuALbKwe1vBJ6E zuul-build-sshkey 2026-02-03 00:14:26.515754 | controller -> localhost | The key's randomart image is: 2026-02-03 00:14:26.515782 | controller -> localhost | +---[RSA 2048]----+ 2026-02-03 00:14:26.515818 | controller -> localhost | |^Bo*O.. | 2026-02-03 00:14:26.515852 | controller -> localhost | |X*o=.+. | 2026-02-03 00:14:26.515878 | controller -> localhost | | o..=o | 2026-02-03 00:14:26.515903 | controller -> localhost | | +.* o | 2026-02-03 00:14:26.515931 | controller -> localhost | |. E B B S | 2026-02-03 00:14:26.515981 | controller -> localhost | | o o * = . | 2026-02-03 00:14:26.516022 | controller -> localhost | |. . . o . | 2026-02-03 00:14:26.516052 | controller -> localhost | | ... . | 2026-02-03 00:14:26.516077 | controller -> localhost | |.... | 2026-02-03 00:14:26.516106 | controller -> localhost | +----[SHA256]-----+ 2026-02-03 00:14:26.516173 | controller -> localhost | ok: Runtime: 0:00:00.102868 2026-02-03 00:14:26.525973 | 2026-02-03 00:14:26.526097 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-03 00:14:26.552297 | controller | ok 2026-02-03 00:14:26.568281 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-03 00:14:26.582882 | 2026-02-03 00:14:26.583014 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-03 00:14:26.607567 | controller | skipping: Conditional result was False 2026-02-03 00:14:26.614615 | 2026-02-03 00:14:26.614718 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-03 00:14:27.253811 | controller | changed 2026-02-03 00:14:27.266518 | 2026-02-03 00:14:27.266658 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-03 00:14:27.503243 | controller | ok 2026-02-03 00:14:27.511433 | 2026-02-03 00:14:27.511544 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-03 00:14:28.175210 | controller | changed 2026-02-03 00:14:28.193392 | 2026-02-03 00:14:28.193559 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-03 00:14:28.873135 | controller | changed 2026-02-03 00:14:28.882910 | 2026-02-03 00:14:28.883007 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-03 00:14:28.919157 | controller | skipping: Conditional result was False 2026-02-03 00:14:28.928979 | 2026-02-03 00:14:28.929076 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-03 00:14:29.395584 | controller -> localhost | changed 2026-02-03 00:14:29.419975 | 2026-02-03 00:14:29.420128 | TASK [add-build-sshkey : Add back temp key] 2026-02-03 00:14:29.753773 | controller -> localhost | Identity added: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_rsa (zuul-build-sshkey) 2026-02-03 00:14:29.753983 | controller -> localhost | ok: Runtime: 0:00:00.008459 2026-02-03 00:14:29.766687 | 2026-02-03 00:14:29.766771 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-03 00:14:30.162474 | controller | ok 2026-02-03 00:14:30.174736 | 2026-02-03 00:14:30.174894 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-03 00:14:30.222978 | controller | skipping: Conditional result was False 2026-02-03 00:14:30.248276 | 2026-02-03 00:14:30.248418 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-03 00:14:30.293199 | controller | ok 2026-02-03 00:14:30.325544 | 2026-02-03 00:14:30.325727 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-03 00:14:30.647379 | controller -> localhost | ok 2026-02-03 00:14:30.654325 | 2026-02-03 00:14:30.654391 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-03 00:14:30.684642 | controller | ok 2026-02-03 00:14:30.695276 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-03 00:14:30.701967 | 2026-02-03 00:14:30.702034 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-03 00:14:31.042864 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-03 00:14:31.043329 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_ecdsa. 2026-02-03 00:14:31.043401 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_ecdsa.pub. 2026-02-03 00:14:31.043498 | controller -> localhost | The key fingerprint is: 2026-02-03 00:14:31.043548 | controller -> localhost | SHA256:euZ9duCdrOvmSpdVp3OZcIOqwxOvdc/97mU158ucFTQ zuul-build-sshkey 2026-02-03 00:14:31.043603 | controller -> localhost | The key's randomart image is: 2026-02-03 00:14:31.043689 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-03 00:14:31.043821 | controller -> localhost | | | 2026-02-03 00:14:31.043868 | controller -> localhost | | . | 2026-02-03 00:14:31.043908 | controller -> localhost | | o Eo| 2026-02-03 00:14:31.043947 | controller -> localhost | | . +o*| 2026-02-03 00:14:31.043985 | controller -> localhost | | S. . +=+| 2026-02-03 00:14:31.044022 | controller -> localhost | | .. + .o +=| 2026-02-03 00:14:31.044059 | controller -> localhost | | . o=.+o= .=| 2026-02-03 00:14:31.044096 | controller -> localhost | | + o=.* X.*| 2026-02-03 00:14:31.044135 | controller -> localhost | | ..oB=+ X*| 2026-02-03 00:14:31.044173 | controller -> localhost | +----[SHA256]-----+ 2026-02-03 00:14:31.044275 | controller -> localhost | ok: Runtime: 0:00:00.018060 2026-02-03 00:14:31.060297 | 2026-02-03 00:14:31.060500 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-03 00:14:31.105100 | controller | ok 2026-02-03 00:14:31.121357 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-03 00:14:31.137042 | 2026-02-03 00:14:31.137158 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-03 00:14:31.165698 | controller | skipping: Conditional result was False 2026-02-03 00:14:31.176881 | 2026-02-03 00:14:31.176970 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-03 00:14:31.472343 | controller | changed 2026-02-03 00:14:31.486398 | 2026-02-03 00:14:31.486551 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-03 00:14:31.733951 | controller | ok 2026-02-03 00:14:31.748552 | 2026-02-03 00:14:31.748740 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-03 00:14:32.462045 | controller | changed 2026-02-03 00:14:32.468117 | 2026-02-03 00:14:32.468209 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-03 00:14:33.081969 | controller | changed 2026-02-03 00:14:33.090301 | 2026-02-03 00:14:33.090435 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-03 00:14:33.116614 | controller | skipping: Conditional result was False 2026-02-03 00:14:33.125604 | 2026-02-03 00:14:33.125760 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-03 00:14:33.410216 | controller -> localhost | changed 2026-02-03 00:14:33.422542 | 2026-02-03 00:14:33.422658 | TASK [add-build-sshkey : Add back temp key] 2026-02-03 00:14:33.695892 | controller -> localhost | Identity added: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/a890feadad7f4b529bd14c74d5ff7259_id_ecdsa (zuul-build-sshkey) 2026-02-03 00:14:33.696090 | controller -> localhost | ok: Runtime: 0:00:00.009787 2026-02-03 00:14:33.702787 | 2026-02-03 00:14:33.702882 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-03 00:14:33.925018 | controller | ok 2026-02-03 00:14:33.937545 | 2026-02-03 00:14:33.937734 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-03 00:14:34.006372 | controller | skipping: Conditional result was False 2026-02-03 00:14:34.023499 | 2026-02-03 00:14:34.023637 | TASK [include_role : remove-zuul-sshkey] 2026-02-03 00:14:34.051224 | controller | skipping: Conditional result was False 2026-02-03 00:14:34.061580 | 2026-02-03 00:14:34.061769 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-03 00:14:34.311849 | controller | ok: "logs" 2026-02-03 00:14:34.312089 | controller | ok: All items complete 2026-02-03 00:14:34.312118 | 2026-02-03 00:14:34.515539 | controller | ok: "artifacts" 2026-02-03 00:14:34.707923 | controller | ok: "docs" 2026-02-03 00:14:34.721898 | 2026-02-03 00:14:34.722062 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-03 00:14:34.983945 | controller | changed: "logs" 2026-02-03 00:14:35.179884 | controller | changed: "artifacts" 2026-02-03 00:14:35.354257 | controller | changed: "docs" 2026-02-03 00:14:35.403653 | 2026-02-03 00:14:35.403773 | PLAY RECAP 2026-02-03 00:14:35.403831 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-03 00:14:35.403857 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-03 00:14:35.403875 | 2026-02-03 00:14:35.586288 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-03 00:14:35.587234 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 00:14:36.285200 | 2026-02-03 00:14:36.285330 | PLAY [all] 2026-02-03 00:14:36.323188 | 2026-02-03 00:14:36.323312 | TASK [Install binary dependencies] 2026-02-03 00:14:36.394475 | controller | ok 2026-02-03 00:14:36.426364 | 2026-02-03 00:14:36.426538 | TASK [bindep : Include find tasks] 2026-02-03 00:14:36.486590 | controller | ok 2026-02-03 00:14:36.498499 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-03 00:14:36.507451 | 2026-02-03 00:14:36.507560 | TASK [bindep : Look for bindep.txt] 2026-02-03 00:14:37.087263 | controller | ok 2026-02-03 00:14:37.100577 | 2026-02-03 00:14:37.100717 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:14:37.137259 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.145572 | 2026-02-03 00:14:37.145709 | TASK [bindep : Look for other-requirements.txt] 2026-02-03 00:14:37.401093 | controller | ok 2026-02-03 00:14:37.409128 | 2026-02-03 00:14:37.409247 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:14:37.476826 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.485128 | 2026-02-03 00:14:37.485251 | TASK [bindep : Look for bindep fallback file] 2026-02-03 00:14:37.542345 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.555004 | 2026-02-03 00:14:37.555126 | TASK [bindep : Define bindep_file fact] 2026-02-03 00:14:37.598873 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.609300 | 2026-02-03 00:14:37.609549 | TASK [bindep : Include bindep tasks] 2026-02-03 00:14:37.649591 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.661617 | 2026-02-03 00:14:37.661770 | TASK [bindep : Include install tasks] 2026-02-03 00:14:37.712431 | controller | skipping: Conditional result was False 2026-02-03 00:14:37.723174 | 2026-02-03 00:14:37.723277 | LOOP [bindep : Include package tasks] 2026-02-03 00:14:37.824277 | 2026-02-03 00:14:37.824467 | TASK [Run test-setup role] 2026-02-03 00:14:37.857150 | controller | ok 2026-02-03 00:14:37.890012 | 2026-02-03 00:14:37.890246 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-03 00:14:38.128394 | controller | ok 2026-02-03 00:14:38.139901 | 2026-02-03 00:14:38.140005 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-03 00:14:38.682388 | controller | skipping: Conditional result was False 2026-02-03 00:14:38.734898 | 2026-02-03 00:14:38.735004 | PLAY RECAP 2026-02-03 00:14:38.735048 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-03 00:14:38.735069 | 2026-02-03 00:14:38.972503 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 00:14:38.973611 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-03 00:14:39.664731 | 2026-02-03 00:14:39.664865 | PLAY [controller] 2026-02-03 00:14:39.688641 | 2026-02-03 00:14:39.688782 | TASK [Create the /root directory] 2026-02-03 00:14:40.280345 | controller | ok 2026-02-03 00:14:40.291170 | 2026-02-03 00:14:40.291296 | TASK [Install glibc-langpack-en] 2026-02-03 00:14:44.263718 | controller | ok: Nothing to do 2026-02-03 00:14:44.270609 | 2026-02-03 00:14:44.270725 | TASK [Ensure controller directory exists] 2026-02-03 00:14:44.487388 | controller | changed 2026-02-03 00:14:44.502819 | 2026-02-03 00:14:44.502964 | TASK [Install container runtime] 2026-02-03 00:14:44.564252 | controller | ok 2026-02-03 00:14:44.609539 | 2026-02-03 00:14:44.609650 | LOOP [ensure-podman : Find distribution installation] 2026-02-03 00:14:44.639553 | controller | ok: "/var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-03 00:14:44.658406 | controller | included: /var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-03 00:14:44.674190 | 2026-02-03 00:14:44.674460 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-03 00:15:48.240063 | controller | changed 2026-02-03 00:15:48.256212 | 2026-02-03 00:15:48.256387 | TASK [ensure-podman : Fetch podman version] 2026-02-03 00:15:48.885247 | controller | Client: Podman Engine 2026-02-03 00:15:48.914342 | controller | Version: 4.6.2 2026-02-03 00:15:48.914375 | controller | API Version: 4.6.2 2026-02-03 00:15:48.914383 | controller | Go Version: go1.19.12 2026-02-03 00:15:48.914401 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-03 00:15:48.914409 | controller | OS/Arch: linux/amd64 2026-02-03 00:15:49.313843 | controller | ok: Runtime: 0:00:00.216935 2026-02-03 00:15:49.333528 | 2026-02-03 00:15:49.333837 | TASK [ensure-podman : Print podman version installed] 2026-02-03 00:15:49.392364 | Podman version: Client: Podman Engine 2026-02-03 00:15:49.392742 | Version: 4.6.2 2026-02-03 00:15:49.392824 | API Version: 4.6.2 2026-02-03 00:15:49.392903 | Go Version: go1.19.12 2026-02-03 00:15:49.392954 | Built: Mon Aug 28 19:38:31 2023 2026-02-03 00:15:49.393001 | OS/Arch: linux/amd64 2026-02-03 00:15:49.408768 | 2026-02-03 00:15:49.408866 | TASK [ensure-podman : Validate podman engine] 2026-02-03 00:15:49.975781 | controller | skipping: Conditional result was False 2026-02-03 00:15:49.993532 | 2026-02-03 00:15:49.993796 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-03 00:15:50.022355 | controller | skipping: Conditional result was False 2026-02-03 00:15:50.053406 | 2026-02-03 00:15:50.053569 | TASK [Ensure python3.8 is present] 2026-02-03 00:15:50.080964 | controller | skipping: Conditional result was False 2026-02-03 00:15:50.090138 | 2026-02-03 00:15:50.090227 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-03 00:15:50.125382 | controller | ok 2026-02-03 00:15:50.156610 | 2026-02-03 00:15:50.156775 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-03 00:15:51.622407 | controller | ok: Nothing to do 2026-02-03 00:15:51.628083 | 2026-02-03 00:15:51.628144 | TASK [our-ensure-python : Also install python3-devel] 2026-02-03 00:16:00.693884 | controller | changed 2026-02-03 00:16:00.718839 | 2026-02-03 00:16:00.718961 | TASK [Run ensure-virtualenv role] 2026-02-03 00:16:00.744097 | controller | ok 2026-02-03 00:16:00.774325 | 2026-02-03 00:16:00.774466 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-03 00:16:01.057582 | controller | /usr/bin/virtualenv 2026-02-03 00:16:01.338018 | controller | ok: Runtime: 0:00:00.005251 2026-02-03 00:16:01.345563 | 2026-02-03 00:16:01.345650 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-03 00:16:01.385326 | controller | skipping: Conditional result was False 2026-02-03 00:16:01.385777 | controller | ok: All items complete 2026-02-03 00:16:01.385836 | 2026-02-03 00:16:01.402418 | 2026-02-03 00:16:01.402561 | TASK [Find the full path of the Python interpreter] 2026-02-03 00:16:01.619692 | controller | /usr/bin/python3 2026-02-03 00:16:01.933823 | controller | ok 2026-02-03 00:16:01.947512 | 2026-02-03 00:16:01.947712 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-03 00:16:02.801480 | controller | created virtual environment CPython3.11.0.final.0-64 in 460ms 2026-02-03 00:16:02.817182 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-03 00:16:02.817227 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-02-03 00:16:02.817236 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-03 00:16:02.817250 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-03 00:16:03.023347 | controller | changed 2026-02-03 00:16:03.033359 | 2026-02-03 00:16:03.033467 | TASK [Set selinux package] 2026-02-03 00:16:03.066941 | controller | ok 2026-02-03 00:16:03.073996 | 2026-02-03 00:16:03.074080 | TASK [Set selinux package (Fedora)] 2026-02-03 00:16:03.125481 | controller | ok 2026-02-03 00:16:03.133070 | 2026-02-03 00:16:03.133166 | TASK [Install selinux into virtualenv] 2026-02-03 00:16:28.580101 | controller | Collecting selinux-please-lie-to-me 2026-02-03 00:16:40.904808 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-03 00:16:41.269864 | controller | Collecting setuptools<50.0.0 2026-02-03 00:16:41.275408 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-03 00:16:41.329963 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.4 MB/s eta 0:00:00 2026-02-03 00:16:41.415897 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-03 00:16:41.416055 | controller | Attempting uninstall: setuptools 2026-02-03 00:16:41.418475 | controller | Found existing installation: setuptools 62.6.0 2026-02-03 00:16:41.478128 | controller | Uninstalling setuptools-62.6.0: 2026-02-03 00:16:41.487340 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-03 00:16:41.849358 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-03 00:16:53.223835 | controller | 2026-02-03 00:16:53.334174 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-03 00:16:53.334265 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-03 00:16:53.695402 | controller | ok: Runtime: 0:00:49.981683 2026-02-03 00:16:53.703627 | 2026-02-03 00:16:53.703794 | TASK [Install pytest-forked into virtualenv] 2026-02-03 00:17:03.476941 | controller | Collecting pytest-forked 2026-02-03 00:17:15.789699 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-03 00:17:15.831881 | controller | Collecting py 2026-02-03 00:17:15.847995 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-03 00:17:15.868456 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.4 MB/s eta 0:00:00 2026-02-03 00:17:15.984827 | controller | Collecting pytest>=3.10 2026-02-03 00:17:15.990851 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-03 00:17:16.005321 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 32.5 MB/s eta 0:00:00 2026-02-03 00:17:16.050913 | controller | Collecting iniconfig>=1.0.1 2026-02-03 00:17:16.054401 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-03 00:17:16.097649 | controller | Collecting packaging>=22 2026-02-03 00:17:16.100886 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-03 00:17:16.107033 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 18.4 MB/s eta 0:00:00 2026-02-03 00:17:16.136522 | controller | Collecting pluggy<2,>=1.5 2026-02-03 00:17:16.139851 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-03 00:17:16.186115 | controller | Collecting pygments>=2.7.2 2026-02-03 00:17:16.196366 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-03 00:17:16.213759 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 81.2 MB/s eta 0:00:00 2026-02-03 00:17:16.283095 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-03 00:17:17.407838 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-03 00:17:17.417086 | controller | 2026-02-03 00:17:17.515726 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-03 00:17:17.515775 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-03 00:17:17.791957 | controller | ok: Runtime: 0:00:23.542679 2026-02-03 00:17:17.800522 | 2026-02-03 00:17:17.800609 | TASK [Update pip] 2026-02-03 00:17:18.382440 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-03 00:17:28.178634 | controller | Collecting pip 2026-02-03 00:17:52.299273 | controller | Downloading pip-26.0-py3-none-any.whl (1.8 MB) 2026-02-03 00:17:52.358040 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.3 MB/s eta 0:00:00 2026-02-03 00:17:52.427496 | controller | Installing collected packages: pip 2026-02-03 00:17:52.427648 | controller | Attempting uninstall: pip 2026-02-03 00:17:52.430040 | controller | Found existing installation: pip 22.2.2 2026-02-03 00:17:52.580996 | controller | Uninstalling pip-22.2.2: 2026-02-03 00:17:52.598734 | controller | Successfully uninstalled pip-22.2.2 2026-02-03 00:17:53.433898 | controller | Successfully installed pip-26.0 2026-02-03 00:17:53.867218 | controller | ok: Runtime: 0:00:35.528361 2026-02-03 00:17:53.874297 | 2026-02-03 00:17:53.874365 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-03 00:17:54.120376 | controller | changed 2026-02-03 00:17:54.127762 | 2026-02-03 00:17:54.127860 | TASK [Install ansible into virtualenv] 2026-02-03 00:17:54.701841 | controller | Processing ./src/github.com/ansible/ansible 2026-02-03 00:17:54.704839 | controller | Installing build dependencies: started 2026-02-03 00:18:19.940447 | controller | Installing build dependencies: finished with status 'done' 2026-02-03 00:18:19.941020 | controller | Getting requirements to build wheel: started 2026-02-03 00:18:20.716795 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-03 00:18:20.717638 | controller | Preparing metadata (pyproject.toml): started 2026-02-03 00:18:21.194597 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-03 00:18:21.199256 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-02-03 00:18:21.203021 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-03 00:18:21.731178 | controller | ERROR 2026-02-03 00:18:21.731456 | controller | { 2026-02-03 00:18:21.731507 | controller | "delta": "0:00:26.872813", 2026-02-03 00:18:21.731536 | controller | "end": "2026-02-03 00:18:21.264655", 2026-02-03 00:18:21.731560 | controller | "msg": "non-zero return code", 2026-02-03 00:18:21.731598 | controller | "rc": 1, 2026-02-03 00:18:21.731622 | controller | "start": "2026-02-03 00:17:54.391842" 2026-02-03 00:18:21.731644 | controller | } failure 2026-02-03 00:18:21.734432 | 2026-02-03 00:18:21.734507 | PLAY RECAP 2026-02-03 00:18:21.734570 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-03 00:18:21.734600 | 2026-02-03 00:18:21.879978 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-03 00:18:21.882083 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 00:18:22.588844 | 2026-02-03 00:18:22.588982 | PLAY [all] 2026-02-03 00:18:22.611856 | 2026-02-03 00:18:22.611967 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-03 00:18:23.057791 | controller | changed: non-zero return code 2026-02-03 00:18:23.066141 | 2026-02-03 00:18:23.066247 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-03 00:18:23.092920 | controller | skipping: Conditional result was False 2026-02-03 00:18:23.101986 | 2026-02-03 00:18:23.102095 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-03 00:18:23.136788 | 2026-02-03 00:18:23.136950 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-03 00:18:23.184271 | 2026-02-03 00:18:23.184570 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-03 00:18:23.210777 | controller | skipping: Conditional result was False 2026-02-03 00:18:23.229377 | 2026-02-03 00:18:23.229501 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-03 00:18:23.275391 | 2026-02-03 00:18:23.275654 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-03 00:18:23.305498 | controller | skipping: Conditional result was False 2026-02-03 00:18:23.316358 | 2026-02-03 00:18:23.316474 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-03 00:18:23.342171 | controller | skipping: Conditional result was False 2026-02-03 00:18:23.351988 | 2026-02-03 00:18:23.352081 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-03 00:18:23.377495 | controller | skipping: Conditional result was False 2026-02-03 00:18:23.415049 | 2026-02-03 00:18:23.415139 | PLAY RECAP 2026-02-03 00:18:23.415198 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-03 00:18:23.415227 | 2026-02-03 00:18:23.527337 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 00:18:23.530255 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-03 00:18:24.134998 | 2026-02-03 00:18:24.135140 | PLAY [all:!appliance*] 2026-02-03 00:18:24.156944 | 2026-02-03 00:18:24.157102 | TASK [unregister the node] 2026-02-03 00:18:24.230749 | controller | skipping: Conditional result was False 2026-02-03 00:18:24.245120 | 2026-02-03 00:18:24.245304 | TASK [include_role : fetch-output] 2026-02-03 00:18:24.296402 | controller | ok 2026-02-03 00:18:24.343128 | 2026-02-03 00:18:24.343314 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-03 00:18:24.389424 | controller | skipping: Conditional result was False 2026-02-03 00:18:24.399338 | 2026-02-03 00:18:24.399453 | TASK [fetch-output : Set log path for single node] 2026-02-03 00:18:24.452808 | controller | ok 2026-02-03 00:18:24.458688 | 2026-02-03 00:18:24.458760 | LOOP [fetch-output : Ensure local output dirs] 2026-02-03 00:18:24.898008 | controller -> localhost | ok: "/var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/logs" 2026-02-03 00:18:25.153122 | controller -> localhost | changed: "/var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/artifacts" 2026-02-03 00:18:25.435179 | controller -> localhost | changed: "/var/lib/zuul/builds/a890feadad7f4b529bd14c74d5ff7259/work/docs" 2026-02-03 00:18:25.457011 | 2026-02-03 00:18:25.457219 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-03 00:18:26.249228 | controller | changed: 2026-02-03 00:18:26.249611 | controller | .d..t...... ./ 2026-02-03 00:18:26.249708 | controller | cd+++++++++ controller/ 2026-02-03 00:18:26.249786 | controller | changed: All items complete 2026-02-03 00:18:26.249829 | 2026-02-03 00:18:26.752895 | controller | changed: .d..t...... ./ 2026-02-03 00:18:27.272904 | controller | changed: .d..t...... ./ 2026-02-03 00:18:27.295507 | 2026-02-03 00:18:27.295766 | TASK [include_role : fetch-output-openshift] 2026-02-03 00:18:27.335154 | controller | skipping: Conditional result was False 2026-02-03 00:18:27.345018 | 2026-02-03 00:18:27.345140 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-03 00:18:27.380367 | controller | skipping: Conditional result was False 2026-02-03 00:18:27.393134 | controller | skipping: Conditional result was False 2026-02-03 00:18:27.479606 | 2026-02-03 00:18:27.479757 | PLAY [localhost] 2026-02-03 00:18:27.504044 | 2026-02-03 00:18:27.504173 | TASK [Run Zuul manifest role] 2026-02-03 00:18:27.528487 | localhost | ok 2026-02-03 00:18:27.545205 | 2026-02-03 00:18:27.545463 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-03 00:18:27.991360 | localhost | changed 2026-02-03 00:18:27.995998 | 2026-02-03 00:18:27.998566 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-03 00:18:28.026575 | localhost | ok 2026-02-03 00:18:28.035927 | 2026-02-03 00:18:28.036012 | TASK [Set zuul-log-path fact] 2026-02-03 00:18:28.054449 | localhost | ok 2026-02-03 00:18:28.078318 | 2026-02-03 00:18:28.078391 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 00:18:28.106603 | localhost | ok 2026-02-03 00:18:28.115447 | 2026-02-03 00:18:28.115513 | LOOP [Run upload-logs-swift role] 2026-02-03 00:18:28.172520 | localhost | Output suppressed because no_log was given 2026-02-03 00:18:28.217502 | 2026-02-03 00:18:28.217605 | TASK [Set zuul-log-path fact] 2026-02-03 00:18:28.242537 | localhost | skipping: Conditional result was False 2026-02-03 00:18:28.247523 | 2026-02-03 00:18:28.247587 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-03 00:18:28.708478 | localhost -> localhost | ok: Runtime: 0:00:00.010453 2026-02-03 00:18:28.767835 | 2026-02-03 00:18:28.767999 | TASK [upload-logs-swift : Upload logs to swift]