2026-02-05 00:20:36.988356 | Job console starting... 2026-02-05 00:20:36.998900 | Updating repositories 2026-02-05 00:20:37.157115 | Preparing job workspace 2026-02-05 00:20:41.166550 | Running Ansible setup... 2026-02-05 00:20:49.189175 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-05 00:20:49.789337 | 2026-02-05 00:20:49.789467 | PLAY [localhost] 2026-02-05 00:20:49.797585 | 2026-02-05 00:20:49.797654 | TASK [Gathering Facts] 2026-02-05 00:20:50.878723 | localhost | ok 2026-02-05 00:20:50.912141 | 2026-02-05 00:20:50.912315 | TASK [Setup log path fact] 2026-02-05 00:20:50.934092 | localhost | ok 2026-02-05 00:20:50.950658 | 2026-02-05 00:20:50.950951 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-05 00:20:50.991269 | localhost | ok 2026-02-05 00:20:51.001824 | 2026-02-05 00:20:51.001968 | TASK [emit-job-header : Print job information] 2026-02-05 00:20:51.056076 | # Job Information 2026-02-05 00:20:51.056296 | Ansible Version: 2.15.12 2026-02-05 00:20:51.056368 | Job: ansible-test-sanity-docker-devel 2026-02-05 00:20:51.056417 | Pipeline: periodic 2026-02-05 00:20:51.056459 | Executor: ze02.softwarefactory-project.io 2026-02-05 00:20:51.056499 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-05 00:20:51.056546 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/c52/ansible/c52ab59cba5248c08a0a1a4dc4243c36/ 2026-02-05 00:20:51.056591 | Event ID: 9feee7bbbe884a658b69c76d84949d2e 2026-02-05 00:20:51.065320 | 2026-02-05 00:20:51.065458 | LOOP [emit-job-header : Print node information] 2026-02-05 00:20:51.184392 | localhost | ok: 2026-02-05 00:20:51.185138 | localhost | # Node Information 2026-02-05 00:20:51.185217 | localhost | Inventory Hostname: controller 2026-02-05 00:20:51.185265 | localhost | Hostname: np0005609084 2026-02-05 00:20:51.185309 | localhost | Username: zuul 2026-02-05 00:20:51.185363 | localhost | Distro: Fedora 37 2026-02-05 00:20:51.185407 | localhost | Provider: ansible-vexxhost-ams1 2026-02-05 00:20:51.185447 | localhost | Region: ams1 2026-02-05 00:20:51.185485 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-05 00:20:51.185522 | localhost | Product Name: OpenStack Nova 2026-02-05 00:20:51.185560 | localhost | Interface IP: 38.129.16.144 2026-02-05 00:20:51.205728 | 2026-02-05 00:20:51.205943 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-05 00:20:51.645185 | localhost -> localhost | changed 2026-02-05 00:20:51.659606 | 2026-02-05 00:20:51.659803 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-05 00:20:52.541288 | localhost -> localhost | changed 2026-02-05 00:20:52.588227 | 2026-02-05 00:20:52.588349 | PLAY [all:!appliance*] 2026-02-05 00:20:52.612795 | 2026-02-05 00:20:52.612901 | TASK [include_role : start-zuul-console] 2026-02-05 00:20:52.636272 | controller | ok 2026-02-05 00:20:52.656329 | 2026-02-05 00:20:52.656424 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-05 00:20:53.753145 | controller | ok 2026-02-05 00:20:53.782408 | 2026-02-05 00:20:53.782613 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-05 00:20:56.424514 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-05 00:20:56.442890 | 2026-02-05 00:20:56.443093 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-05 00:20:56.835027 | controller | skipping: Conditional result was False 2026-02-05 00:20:56.845024 | 2026-02-05 00:20:56.845142 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-05 00:20:56.870191 | controller | skipping: Conditional result was False 2026-02-05 00:20:56.881409 | 2026-02-05 00:20:56.881590 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-05 00:20:56.909426 | controller | skipping: Conditional result was False 2026-02-05 00:20:56.930928 | 2026-02-05 00:20:56.931173 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-05 00:20:56.968076 | controller | skipping: Conditional result was False 2026-02-05 00:20:56.977399 | 2026-02-05 00:20:56.977499 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-05 00:20:57.013077 | controller | skipping: Conditional result was False 2026-02-05 00:20:57.022273 | 2026-02-05 00:20:57.022368 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-05 00:20:57.048141 | controller | skipping: Conditional result was False 2026-02-05 00:20:57.062050 | 2026-02-05 00:20:57.062159 | TASK [Disable Fedora Modular] 2026-02-05 00:20:58.255393 | controller | changed 2026-02-05 00:20:58.270301 | 2026-02-05 00:20:58.270456 | TASK [Enable EPEL] 2026-02-05 00:20:58.308727 | controller | skipping: Conditional result was False 2026-02-05 00:20:58.324824 | 2026-02-05 00:20:58.325001 | TASK [Register the RHEL node] 2026-02-05 00:20:58.750246 | 2026-02-05 00:20:58.750564 | TASK [Show the subscription-manager status] 2026-02-05 00:20:59.148988 | controller | skipping: Conditional result was False 2026-02-05 00:20:59.158050 | 2026-02-05 00:20:59.158139 | TASK [Enable EPEL on RHEL] 2026-02-05 00:20:59.535611 | controller | skipping: Conditional result was False 2026-02-05 00:20:59.550872 | 2026-02-05 00:20:59.551034 | TASK [Install git and tox] 2026-02-05 00:23:07.425212 | controller | changed 2026-02-05 00:23:07.439568 | 2026-02-05 00:23:07.439756 | TASK [include_role : prepare-workspace] 2026-02-05 00:23:07.478938 | controller | ok 2026-02-05 00:23:07.517857 | 2026-02-05 00:23:07.518063 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-05 00:23:08.439395 | controller | ok 2026-02-05 00:23:08.455231 | 2026-02-05 00:23:08.455511 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-05 00:23:24.246481 | controller | Output suppressed because no_log was given 2026-02-05 00:23:24.260348 | 2026-02-05 00:23:24.260432 | TASK [include_role : prepare-workspace-openshift] 2026-02-05 00:23:24.290064 | controller | skipping: Conditional result was False 2026-02-05 00:23:24.341083 | 2026-02-05 00:23:24.341211 | PLAY [all:!appliance] 2026-02-05 00:23:24.365803 | 2026-02-05 00:23:24.365926 | TASK [Run add-build-sshkey role (RSA)] 2026-02-05 00:23:24.400532 | controller | ok 2026-02-05 00:23:24.423442 | 2026-02-05 00:23:24.423558 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-05 00:23:24.724868 | controller -> localhost | ok 2026-02-05 00:23:24.739916 | 2026-02-05 00:23:24.740058 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-05 00:23:24.779412 | controller | ok 2026-02-05 00:23:24.807721 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-05 00:23:24.815637 | 2026-02-05 00:23:24.815841 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-05 00:23:25.300254 | controller -> localhost | Generating public/private rsa key pair. 2026-02-05 00:23:25.300769 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_rsa. 2026-02-05 00:23:25.300854 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_rsa.pub. 2026-02-05 00:23:25.300927 | controller -> localhost | The key fingerprint is: 2026-02-05 00:23:25.300981 | controller -> localhost | SHA256:Oesr/3JPWqRqp4cFexALfrRAmq5vALln41Xr8dIA6bw zuul-build-sshkey 2026-02-05 00:23:25.301032 | controller -> localhost | The key's randomart image is: 2026-02-05 00:23:25.301078 | controller -> localhost | +---[RSA 2048]----+ 2026-02-05 00:23:25.301124 | controller -> localhost | | .. | 2026-02-05 00:23:25.301168 | controller -> localhost | | oo o | 2026-02-05 00:23:25.301213 | controller -> localhost | | . oo + + | 2026-02-05 00:23:25.301255 | controller -> localhost | |o .o o *. | 2026-02-05 00:23:25.301300 | controller -> localhost | | o o.o oS+ . | 2026-02-05 00:23:25.301359 | controller -> localhost | |. =.+ + .ooo | 2026-02-05 00:23:25.301417 | controller -> localhost | | +.+ o =.+. o | 2026-02-05 00:23:25.301470 | controller -> localhost | | ..E +.*.++ | 2026-02-05 00:23:25.301515 | controller -> localhost | | .. =*Oo.. | 2026-02-05 00:23:25.301567 | controller -> localhost | +----[SHA256]-----+ 2026-02-05 00:23:25.301721 | controller -> localhost | ok: Runtime: 0:00:00.052327 2026-02-05 00:23:25.319375 | 2026-02-05 00:23:25.319581 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-05 00:23:25.364362 | controller | ok 2026-02-05 00:23:25.387706 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-05 00:23:25.402272 | 2026-02-05 00:23:25.402368 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-05 00:23:25.430616 | controller | skipping: Conditional result was False 2026-02-05 00:23:25.445576 | 2026-02-05 00:23:25.445779 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-05 00:23:26.545597 | controller | changed 2026-02-05 00:23:26.555821 | 2026-02-05 00:23:26.555911 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-05 00:23:27.271087 | controller | ok 2026-02-05 00:23:27.287898 | 2026-02-05 00:23:27.288047 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-05 00:23:30.386684 | controller | changed 2026-02-05 00:23:30.392994 | 2026-02-05 00:23:30.393074 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-05 00:23:33.462842 | controller | changed 2026-02-05 00:23:33.476078 | 2026-02-05 00:23:33.476230 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-05 00:23:33.504536 | controller | skipping: Conditional result was False 2026-02-05 00:23:33.515694 | 2026-02-05 00:23:33.515804 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-05 00:23:33.931076 | controller -> localhost | changed 2026-02-05 00:23:33.958902 | 2026-02-05 00:23:33.959063 | TASK [add-build-sshkey : Add back temp key] 2026-02-05 00:23:34.303734 | controller -> localhost | Identity added: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_rsa (zuul-build-sshkey) 2026-02-05 00:23:34.303964 | controller -> localhost | ok: Runtime: 0:00:00.012598 2026-02-05 00:23:34.310747 | 2026-02-05 00:23:34.310822 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-05 00:23:35.298836 | controller | ok 2026-02-05 00:23:35.312353 | 2026-02-05 00:23:35.312513 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-05 00:23:35.340071 | controller | skipping: Conditional result was False 2026-02-05 00:23:35.364966 | 2026-02-05 00:23:35.365108 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-05 00:23:35.395242 | controller | ok 2026-02-05 00:23:35.422906 | 2026-02-05 00:23:35.423014 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-05 00:23:35.682029 | controller -> localhost | ok 2026-02-05 00:23:35.692257 | 2026-02-05 00:23:35.692365 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-05 00:23:35.716435 | controller | ok 2026-02-05 00:23:35.732147 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-05 00:23:35.741164 | 2026-02-05 00:23:35.741256 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-05 00:23:36.070551 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-05 00:23:36.070781 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_ecdsa. 2026-02-05 00:23:36.070820 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_ecdsa.pub. 2026-02-05 00:23:36.070868 | controller -> localhost | The key fingerprint is: 2026-02-05 00:23:36.070899 | controller -> localhost | SHA256:hDhY69jS+40znLHt3oNZBXowM2KZ1xnnE/AWrP7XTr8 zuul-build-sshkey 2026-02-05 00:23:36.070929 | controller -> localhost | The key's randomart image is: 2026-02-05 00:23:36.070954 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-05 00:23:36.070977 | controller -> localhost | | . o .o=+ | 2026-02-05 00:23:36.070997 | controller -> localhost | | o o=.* ++.o | 2026-02-05 00:23:36.071016 | controller -> localhost | | . +..o.* o= | 2026-02-05 00:23:36.071034 | controller -> localhost | | = . .. o... | 2026-02-05 00:23:36.071051 | controller -> localhost | | o + So . | 2026-02-05 00:23:36.071069 | controller -> localhost | | . .. o | 2026-02-05 00:23:36.071086 | controller -> localhost | | .. = + . ..| 2026-02-05 00:23:36.071102 | controller -> localhost | | .*o+.. . ..o| 2026-02-05 00:23:36.071119 | controller -> localhost | | o=+ .. . E+| 2026-02-05 00:23:36.071139 | controller -> localhost | +----[SHA256]-----+ 2026-02-05 00:23:36.071201 | controller -> localhost | ok: Runtime: 0:00:00.015016 2026-02-05 00:23:36.080315 | 2026-02-05 00:23:36.080403 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-05 00:23:36.207939 | controller | ok 2026-02-05 00:23:36.215323 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-05 00:23:36.224334 | 2026-02-05 00:23:36.224410 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-05 00:23:36.248335 | controller | skipping: Conditional result was False 2026-02-05 00:23:36.255878 | 2026-02-05 00:23:36.255976 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-05 00:23:37.269858 | controller | changed 2026-02-05 00:23:37.287532 | 2026-02-05 00:23:37.287731 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-05 00:23:37.992087 | controller | ok 2026-02-05 00:23:38.007302 | 2026-02-05 00:23:38.007471 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-05 00:23:41.207285 | controller | changed 2026-02-05 00:23:41.221552 | 2026-02-05 00:23:41.221781 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-05 00:23:44.405192 | controller | changed 2026-02-05 00:23:44.419800 | 2026-02-05 00:23:44.419965 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-05 00:23:44.461029 | controller | skipping: Conditional result was False 2026-02-05 00:23:44.476460 | 2026-02-05 00:23:44.476634 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-05 00:23:44.770345 | controller -> localhost | changed 2026-02-05 00:23:44.798167 | 2026-02-05 00:23:44.798328 | TASK [add-build-sshkey : Add back temp key] 2026-02-05 00:23:45.135482 | controller -> localhost | Identity added: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/c52ab59cba5248c08a0a1a4dc4243c36_id_ecdsa (zuul-build-sshkey) 2026-02-05 00:23:45.135905 | controller -> localhost | ok: Runtime: 0:00:00.014803 2026-02-05 00:23:45.150887 | 2026-02-05 00:23:45.151053 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-05 00:23:45.880297 | controller | ok 2026-02-05 00:23:45.892127 | 2026-02-05 00:23:45.892274 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-05 00:23:45.939809 | controller | skipping: Conditional result was False 2026-02-05 00:23:45.964958 | 2026-02-05 00:23:45.965097 | TASK [include_role : remove-zuul-sshkey] 2026-02-05 00:23:45.993028 | controller | skipping: Conditional result was False 2026-02-05 00:23:46.009861 | 2026-02-05 00:23:46.010027 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-05 00:23:46.712109 | controller | ok: "logs" 2026-02-05 00:23:46.712347 | controller | ok: All items complete 2026-02-05 00:23:46.712382 | 2026-02-05 00:23:47.399456 | controller | ok: "artifacts" 2026-02-05 00:23:48.101495 | controller | ok: "docs" 2026-02-05 00:23:48.116215 | 2026-02-05 00:23:48.116342 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-05 00:23:48.807776 | controller | changed: "logs" 2026-02-05 00:23:49.528985 | controller | changed: "artifacts" 2026-02-05 00:23:50.224841 | controller | changed: "docs" 2026-02-05 00:23:50.283443 | 2026-02-05 00:23:50.283737 | PLAY RECAP 2026-02-05 00:23:50.283817 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-05 00:23:50.283855 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-05 00:23:50.283881 | 2026-02-05 00:23:50.508113 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-05 00:23:50.509325 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-05 00:23:51.048768 | 2026-02-05 00:23:51.048875 | PLAY [all] 2026-02-05 00:23:51.070890 | 2026-02-05 00:23:51.070986 | TASK [Install binary dependencies] 2026-02-05 00:23:51.131475 | controller | ok 2026-02-05 00:23:51.151247 | 2026-02-05 00:23:51.151334 | TASK [bindep : Include find tasks] 2026-02-05 00:23:51.194293 | controller | ok 2026-02-05 00:23:51.205315 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-05 00:23:51.213969 | 2026-02-05 00:23:51.214058 | TASK [bindep : Look for bindep.txt] 2026-02-05 00:23:52.196191 | controller | ok 2026-02-05 00:23:52.214501 | 2026-02-05 00:23:52.214754 | TASK [bindep : Define bindep_file fact] 2026-02-05 00:23:52.243468 | controller | skipping: Conditional result was False 2026-02-05 00:23:52.253030 | 2026-02-05 00:23:52.253131 | TASK [bindep : Look for other-requirements.txt] 2026-02-05 00:23:52.911073 | controller | ok 2026-02-05 00:23:52.927168 | 2026-02-05 00:23:52.927383 | TASK [bindep : Define bindep_file fact] 2026-02-05 00:23:52.965813 | controller | skipping: Conditional result was False 2026-02-05 00:23:52.982208 | 2026-02-05 00:23:52.982385 | TASK [bindep : Look for bindep fallback file] 2026-02-05 00:23:53.020054 | controller | skipping: Conditional result was False 2026-02-05 00:23:53.030072 | 2026-02-05 00:23:53.030203 | TASK [bindep : Define bindep_file fact] 2026-02-05 00:23:53.055893 | controller | skipping: Conditional result was False 2026-02-05 00:23:53.067898 | 2026-02-05 00:23:53.068041 | TASK [bindep : Include bindep tasks] 2026-02-05 00:23:53.104700 | controller | skipping: Conditional result was False 2026-02-05 00:23:53.116643 | 2026-02-05 00:23:53.116964 | TASK [bindep : Include install tasks] 2026-02-05 00:23:53.142997 | controller | skipping: Conditional result was False 2026-02-05 00:23:53.154900 | 2026-02-05 00:23:53.155054 | LOOP [bindep : Include package tasks] 2026-02-05 00:23:53.225287 | 2026-02-05 00:23:53.225470 | TASK [Run test-setup role] 2026-02-05 00:23:53.245844 | controller | ok 2026-02-05 00:23:53.263660 | 2026-02-05 00:23:53.263856 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-05 00:23:54.035848 | controller | ok 2026-02-05 00:23:54.049925 | 2026-02-05 00:23:54.050059 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-05 00:23:54.424958 | controller | skipping: Conditional result was False 2026-02-05 00:23:54.483123 | 2026-02-05 00:23:54.483333 | PLAY RECAP 2026-02-05 00:23:54.483403 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-05 00:23:54.483432 | 2026-02-05 00:23:54.608535 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-05 00:23:54.609459 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-05 00:23:55.223529 | 2026-02-05 00:23:55.223709 | PLAY [controller] 2026-02-05 00:23:55.245253 | 2026-02-05 00:23:55.245349 | TASK [Create the /root directory] 2026-02-05 00:23:56.473142 | controller | ok 2026-02-05 00:23:56.486310 | 2026-02-05 00:23:56.486460 | TASK [Install glibc-langpack-en] 2026-02-05 00:24:04.721505 | controller | ok: Nothing to do 2026-02-05 00:24:04.736374 | 2026-02-05 00:24:04.736579 | TASK [Ensure controller directory exists] 2026-02-05 00:24:05.524890 | controller | changed 2026-02-05 00:24:05.537587 | 2026-02-05 00:24:05.537780 | TASK [Install container runtime] 2026-02-05 00:24:05.617875 | controller | ok 2026-02-05 00:24:05.678195 | 2026-02-05 00:24:05.678384 | LOOP [ensure-podman : Find distribution installation] 2026-02-05 00:24:05.708051 | controller | ok: "/var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-05 00:24:05.726316 | controller | included: /var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-05 00:24:05.738666 | 2026-02-05 00:24:05.738804 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-05 00:26:09.030134 | controller | changed 2026-02-05 00:26:09.045201 | 2026-02-05 00:26:09.045378 | TASK [ensure-podman : Fetch podman version] 2026-02-05 00:26:10.220895 | controller | Client: Podman Engine 2026-02-05 00:26:10.221001 | controller | Version: 4.6.2 2026-02-05 00:26:10.221046 | controller | API Version: 4.6.2 2026-02-05 00:26:10.221088 | controller | Go Version: go1.19.12 2026-02-05 00:26:10.221141 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-05 00:26:10.221182 | controller | OS/Arch: linux/amd64 2026-02-05 00:26:10.423250 | controller | ok: Runtime: 0:00:00.267221 2026-02-05 00:26:10.437512 | 2026-02-05 00:26:10.437715 | TASK [ensure-podman : Print podman version installed] 2026-02-05 00:26:10.466699 | Podman version: Client: Podman Engine 2026-02-05 00:26:10.467018 | Version: 4.6.2 2026-02-05 00:26:10.467078 | API Version: 4.6.2 2026-02-05 00:26:10.467121 | Go Version: go1.19.12 2026-02-05 00:26:10.467161 | Built: Mon Aug 28 19:38:31 2023 2026-02-05 00:26:10.467202 | OS/Arch: linux/amd64 2026-02-05 00:26:10.479971 | 2026-02-05 00:26:10.480103 | TASK [ensure-podman : Validate podman engine] 2026-02-05 00:26:10.848998 | controller | skipping: Conditional result was False 2026-02-05 00:26:10.864643 | 2026-02-05 00:26:10.864849 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-05 00:26:10.892560 | controller | skipping: Conditional result was False 2026-02-05 00:26:10.919939 | 2026-02-05 00:26:10.920144 | TASK [Ensure python3.8 is present] 2026-02-05 00:26:10.947910 | controller | skipping: Conditional result was False 2026-02-05 00:26:10.962905 | 2026-02-05 00:26:10.963070 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-05 00:26:10.995140 | controller | ok 2026-02-05 00:26:11.026972 | 2026-02-05 00:26:11.027090 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-05 00:26:14.331219 | controller | ok: Nothing to do 2026-02-05 00:26:14.344632 | 2026-02-05 00:26:14.344849 | TASK [our-ensure-python : Also install python3-devel] 2026-02-05 00:26:29.630928 | controller | changed 2026-02-05 00:26:29.656440 | 2026-02-05 00:26:29.656580 | TASK [Run ensure-virtualenv role] 2026-02-05 00:26:29.681387 | controller | ok 2026-02-05 00:26:29.709895 | 2026-02-05 00:26:29.710008 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-05 00:26:30.600372 | controller | /usr/bin/virtualenv 2026-02-05 00:26:31.102255 | controller | ok: Runtime: 0:00:00.009081 2026-02-05 00:26:31.111105 | 2026-02-05 00:26:31.111196 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-05 00:26:31.148906 | controller | skipping: Conditional result was False 2026-02-05 00:26:31.149400 | controller | ok: All items complete 2026-02-05 00:26:31.149460 | 2026-02-05 00:26:31.178703 | 2026-02-05 00:26:31.178843 | TASK [Find the full path of the Python interpreter] 2026-02-05 00:26:31.942382 | controller | /usr/bin/python3 2026-02-05 00:26:32.547307 | controller | ok 2026-02-05 00:26:32.560115 | 2026-02-05 00:26:32.560263 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-05 00:26:34.366359 | controller | created virtual environment CPython3.11.0.final.0-64 in 882ms 2026-02-05 00:26:34.423874 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-05 00:26:34.423933 | 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-05 00:26:34.423947 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-05 00:26:34.423970 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-05 00:26:34.944324 | controller | changed 2026-02-05 00:26:34.957126 | 2026-02-05 00:26:34.957277 | TASK [Set selinux package] 2026-02-05 00:26:34.995033 | controller | ok 2026-02-05 00:26:35.006697 | 2026-02-05 00:26:35.006817 | TASK [Set selinux package (Fedora)] 2026-02-05 00:26:35.066169 | controller | ok 2026-02-05 00:26:35.077650 | 2026-02-05 00:26:35.077807 | TASK [Install selinux into virtualenv] 2026-02-05 00:26:38.123314 | controller | Collecting selinux-please-lie-to-me 2026-02-05 00:26:38.191252 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-05 00:26:38.703906 | controller | Collecting setuptools<50.0.0 2026-02-05 00:26:38.710324 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-05 00:26:38.777185 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.2 MB/s eta 0:00:00 2026-02-05 00:26:38.937340 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-05 00:26:38.937748 | controller | Attempting uninstall: setuptools 2026-02-05 00:26:38.941489 | controller | Found existing installation: setuptools 62.6.0 2026-02-05 00:26:39.043951 | controller | Uninstalling setuptools-62.6.0: 2026-02-05 00:26:39.059468 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-05 00:26:39.860553 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-05 00:26:40.089285 | controller | 2026-02-05 00:26:40.378033 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-05 00:26:40.378082 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-05 00:26:40.973875 | controller | ok: Runtime: 0:00:04.491291 2026-02-05 00:26:40.985903 | 2026-02-05 00:26:40.986038 | TASK [Install pytest-forked into virtualenv] 2026-02-05 00:26:42.520314 | controller | Collecting pytest-forked 2026-02-05 00:26:42.580155 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-05 00:26:42.643836 | controller | Collecting py 2026-02-05 00:26:42.649922 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-05 00:26:42.683051 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.0 MB/s eta 0:00:00 2026-02-05 00:26:42.892494 | controller | Collecting pytest>=3.10 2026-02-05 00:26:42.901070 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-05 00:26:42.922764 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 23.9 MB/s eta 0:00:00 2026-02-05 00:26:42.992976 | controller | Collecting iniconfig>=1.0.1 2026-02-05 00:26:42.999704 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-05 00:26:43.077178 | controller | Collecting packaging>=22 2026-02-05 00:26:43.089220 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-05 00:26:43.101972 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 6.7 MB/s eta 0:00:00 2026-02-05 00:26:43.152007 | controller | Collecting pluggy<2,>=1.5 2026-02-05 00:26:43.159851 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-05 00:26:43.237744 | controller | Collecting pygments>=2.7.2 2026-02-05 00:26:43.241906 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-05 00:26:43.279548 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 36.3 MB/s eta 0:00:00 2026-02-05 00:26:43.411030 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-05 00:26:45.696765 | 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-05 00:26:45.705463 | controller | 2026-02-05 00:26:45.924693 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-05 00:26:45.924737 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-05 00:26:46.383089 | controller | ok: Runtime: 0:00:04.119172 2026-02-05 00:26:46.397522 | 2026-02-05 00:26:46.397696 | TASK [Update pip] 2026-02-05 00:26:47.815740 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-05 00:26:48.091232 | controller | Collecting pip 2026-02-05 00:26:48.153184 | controller | Downloading pip-26.0-py3-none-any.whl (1.8 MB) 2026-02-05 00:26:48.218409 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 29.5 MB/s eta 0:00:00 2026-02-05 00:26:48.356859 | controller | Installing collected packages: pip 2026-02-05 00:26:48.357169 | controller | Attempting uninstall: pip 2026-02-05 00:26:48.363273 | controller | Found existing installation: pip 22.2.2 2026-02-05 00:26:48.645031 | controller | Uninstalling pip-22.2.2: 2026-02-05 00:26:48.682314 | controller | Successfully uninstalled pip-22.2.2 2026-02-05 00:26:50.646078 | controller | Successfully installed pip-26.0 2026-02-05 00:26:51.299886 | controller | ok: Runtime: 0:00:03.666096 2026-02-05 00:26:51.314079 | 2026-02-05 00:26:51.314241 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-05 00:26:52.216418 | controller | changed 2026-02-05 00:26:52.229469 | 2026-02-05 00:26:52.229602 | TASK [Install ansible into virtualenv] 2026-02-05 00:26:53.530595 | controller | Processing ./src/github.com/ansible/ansible 2026-02-05 00:26:53.537769 | controller | Installing build dependencies: started 2026-02-05 00:26:55.198365 | controller | Installing build dependencies: finished with status 'done' 2026-02-05 00:26:56.674764 | controller | Getting requirements to build wheel: started 2026-02-05 00:26:56.674836 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-05 00:26:56.675912 | controller | Preparing metadata (pyproject.toml): started 2026-02-05 00:26:57.591754 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-05 00:26:57.595189 | 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-05 00:26:57.600242 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-05 00:26:58.129397 | controller | ERROR 2026-02-05 00:26:58.129657 | controller | { 2026-02-05 00:26:58.129731 | controller | "delta": "0:00:04.855968", 2026-02-05 00:26:58.129754 | controller | "end": "2026-02-05 00:26:57.766817", 2026-02-05 00:26:58.129773 | controller | "msg": "non-zero return code", 2026-02-05 00:26:58.129800 | controller | "rc": 1, 2026-02-05 00:26:58.129822 | controller | "start": "2026-02-05 00:26:52.910849" 2026-02-05 00:26:58.129847 | controller | } failure 2026-02-05 00:26:58.131769 | 2026-02-05 00:26:58.131819 | PLAY RECAP 2026-02-05 00:26:58.131862 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-05 00:26:58.131881 | 2026-02-05 00:26:58.270730 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-05 00:26:58.271741 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-05 00:26:58.944208 | 2026-02-05 00:26:58.944333 | PLAY [all] 2026-02-05 00:26:58.964920 | 2026-02-05 00:26:58.965009 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-05 00:27:00.858128 | controller | changed: non-zero return code 2026-02-05 00:27:00.870711 | 2026-02-05 00:27:00.870869 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-05 00:27:00.898940 | controller | skipping: Conditional result was False 2026-02-05 00:27:00.912036 | 2026-02-05 00:27:00.912315 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-05 00:27:00.953164 | 2026-02-05 00:27:00.953449 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-05 00:27:01.003017 | 2026-02-05 00:27:01.003294 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-05 00:27:01.031623 | controller | skipping: Conditional result was False 2026-02-05 00:27:01.047875 | 2026-02-05 00:27:01.048050 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-05 00:27:01.094045 | 2026-02-05 00:27:01.094368 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-05 00:27:01.123641 | controller | skipping: Conditional result was False 2026-02-05 00:27:01.140147 | 2026-02-05 00:27:01.140335 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-05 00:27:01.169060 | controller | skipping: Conditional result was False 2026-02-05 00:27:01.183331 | 2026-02-05 00:27:01.183492 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-05 00:27:01.213611 | controller | skipping: Conditional result was False 2026-02-05 00:27:01.264624 | 2026-02-05 00:27:01.264775 | PLAY RECAP 2026-02-05 00:27:01.264832 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-05 00:27:01.264858 | 2026-02-05 00:27:01.379890 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-05 00:27:01.381929 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-05 00:27:01.987832 | 2026-02-05 00:27:01.987966 | PLAY [all:!appliance*] 2026-02-05 00:27:02.013751 | 2026-02-05 00:27:02.013886 | TASK [unregister the node] 2026-02-05 00:27:02.373231 | controller | skipping: Conditional result was False 2026-02-05 00:27:02.387442 | 2026-02-05 00:27:02.387704 | TASK [include_role : fetch-output] 2026-02-05 00:27:02.427976 | controller | ok 2026-02-05 00:27:02.469257 | 2026-02-05 00:27:02.469436 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-05 00:27:02.535968 | controller | skipping: Conditional result was False 2026-02-05 00:27:02.545985 | 2026-02-05 00:27:02.546118 | TASK [fetch-output : Set log path for single node] 2026-02-05 00:27:02.590182 | controller | ok 2026-02-05 00:27:02.598817 | 2026-02-05 00:27:02.598930 | LOOP [fetch-output : Ensure local output dirs] 2026-02-05 00:27:03.035240 | controller -> localhost | ok: "/var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/logs" 2026-02-05 00:27:03.269375 | controller -> localhost | changed: "/var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/artifacts" 2026-02-05 00:27:03.491485 | controller -> localhost | changed: "/var/lib/zuul/builds/c52ab59cba5248c08a0a1a4dc4243c36/work/docs" 2026-02-05 00:27:03.513138 | 2026-02-05 00:27:03.513337 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-05 00:27:05.821008 | controller | changed: 2026-02-05 00:27:05.821415 | controller | .d..t...... ./ 2026-02-05 00:27:05.821477 | controller | cd+++++++++ controller/ 2026-02-05 00:27:05.821542 | controller | changed: All items complete 2026-02-05 00:27:05.821585 | 2026-02-05 00:27:07.982310 | controller | changed: .d..t...... ./ 2026-02-05 00:27:10.106778 | controller | changed: .d..t...... ./ 2026-02-05 00:27:10.141329 | 2026-02-05 00:27:10.141498 | TASK [include_role : fetch-output-openshift] 2026-02-05 00:27:10.169654 | controller | skipping: Conditional result was False 2026-02-05 00:27:10.185945 | 2026-02-05 00:27:10.186098 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-05 00:27:10.237718 | controller | skipping: Conditional result was False 2026-02-05 00:27:10.249239 | controller | skipping: Conditional result was False 2026-02-05 00:27:10.300281 | 2026-02-05 00:27:10.300400 | PLAY [localhost] 2026-02-05 00:27:10.319777 | 2026-02-05 00:27:10.319866 | TASK [Run Zuul manifest role] 2026-02-05 00:27:10.341271 | localhost | ok 2026-02-05 00:27:10.360420 | 2026-02-05 00:27:10.360510 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-05 00:27:10.788552 | localhost | changed 2026-02-05 00:27:10.793711 | 2026-02-05 00:27:10.793777 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-05 00:27:10.852096 | localhost | ok 2026-02-05 00:27:10.875946 | 2026-02-05 00:27:10.876109 | TASK [Set zuul-log-path fact] 2026-02-05 00:27:10.943212 | localhost | ok 2026-02-05 00:27:10.958646 | 2026-02-05 00:27:10.958755 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-05 00:27:10.999877 | localhost | ok 2026-02-05 00:27:11.008290 | 2026-02-05 00:27:11.008354 | LOOP [Run upload-logs-swift role] 2026-02-05 00:27:11.056400 | localhost | Output suppressed because no_log was given 2026-02-05 00:27:11.094845 | 2026-02-05 00:27:11.094963 | TASK [Set zuul-log-path fact] 2026-02-05 00:27:11.131492 | localhost | skipping: Conditional result was False 2026-02-05 00:27:11.139942 | 2026-02-05 00:27:11.140044 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-05 00:27:11.572272 | localhost -> localhost | ok: Runtime: 0:00:00.007899 2026-02-05 00:27:11.580485 | 2026-02-05 00:27:11.580579 | TASK [upload-logs-swift : Upload logs to swift]