2025-12-30 00:24:50.899245 | Job console starting... 2025-12-30 00:24:50.911197 | Updating repositories 2025-12-30 00:24:51.041957 | Preparing job workspace 2025-12-30 00:24:54.485850 | Running Ansible setup... 2025-12-30 00:24:59.373508 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-30 00:24:59.970160 | 2025-12-30 00:24:59.970286 | PLAY [localhost] 2025-12-30 00:24:59.979683 | 2025-12-30 00:24:59.979769 | TASK [Gathering Facts] 2025-12-30 00:25:00.922137 | localhost | ok 2025-12-30 00:25:00.936640 | 2025-12-30 00:25:00.936752 | TASK [Setup log path fact] 2025-12-30 00:25:00.954759 | localhost | ok 2025-12-30 00:25:00.967740 | 2025-12-30 00:25:00.967836 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-30 00:25:00.995574 | localhost | ok 2025-12-30 00:25:01.003761 | 2025-12-30 00:25:01.003839 | TASK [emit-job-header : Print job information] 2025-12-30 00:25:01.032135 | # Job Information 2025-12-30 00:25:01.032277 | Ansible Version: 2.15.12 2025-12-30 00:25:01.032308 | Job: ansible-test-sanity-docker-devel 2025-12-30 00:25:01.032329 | Pipeline: periodic 2025-12-30 00:25:01.032347 | Executor: ze01.softwarefactory-project.io 2025-12-30 00:25:01.032364 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-30 00:25:01.032384 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/36a/ansible/36a9a9f552704253b9bd0a3d312d984a/ 2025-12-30 00:25:01.032402 | Event ID: 3253ff496aa2446d86190793a25a6b45 2025-12-30 00:25:01.036101 | 2025-12-30 00:25:01.036178 | LOOP [emit-job-header : Print node information] 2025-12-30 00:25:01.144265 | localhost | ok: 2025-12-30 00:25:01.144587 | localhost | # Node Information 2025-12-30 00:25:01.144670 | localhost | Inventory Hostname: controller 2025-12-30 00:25:01.144731 | localhost | Hostname: np0005572405 2025-12-30 00:25:01.144789 | localhost | Username: zuul 2025-12-30 00:25:01.145128 | localhost | Distro: Fedora 37 2025-12-30 00:25:01.145208 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-30 00:25:01.145265 | localhost | Region: ca-ymq-1 2025-12-30 00:25:01.145316 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-30 00:25:01.145364 | localhost | Product Name: OpenStack Nova 2025-12-30 00:25:01.145410 | localhost | Interface IP: 162.253.55.227 2025-12-30 00:25:01.160402 | 2025-12-30 00:25:01.160540 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-30 00:25:01.562532 | localhost -> localhost | changed 2025-12-30 00:25:01.568292 | 2025-12-30 00:25:01.568369 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-30 00:25:02.501670 | localhost -> localhost | changed 2025-12-30 00:25:02.524122 | 2025-12-30 00:25:02.524203 | PLAY [all:!appliance*] 2025-12-30 00:25:02.547164 | 2025-12-30 00:25:02.547315 | TASK [include_role : start-zuul-console] 2025-12-30 00:25:02.567823 | controller | ok 2025-12-30 00:25:02.589076 | 2025-12-30 00:25:02.589202 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-30 00:25:02.960517 | controller | ok 2025-12-30 00:25:02.981048 | 2025-12-30 00:25:02.981344 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-30 00:25:04.059475 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-30 00:25:04.073126 | 2025-12-30 00:25:04.073305 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-30 00:25:04.623575 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.632443 | 2025-12-30 00:25:04.632746 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-30 00:25:04.657625 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.667978 | 2025-12-30 00:25:04.668145 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-30 00:25:04.684822 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.696432 | 2025-12-30 00:25:04.696591 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-30 00:25:04.712132 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.724066 | 2025-12-30 00:25:04.725261 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-30 00:25:04.750603 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.758559 | 2025-12-30 00:25:04.758667 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-30 00:25:04.783097 | controller | skipping: Conditional result was False 2025-12-30 00:25:04.798343 | 2025-12-30 00:25:04.798482 | TASK [Disable Fedora Modular] 2025-12-30 00:25:05.058185 | controller | changed 2025-12-30 00:25:05.067363 | 2025-12-30 00:25:05.067507 | TASK [Enable EPEL] 2025-12-30 00:25:05.092226 | controller | skipping: Conditional result was False 2025-12-30 00:25:05.100238 | 2025-12-30 00:25:05.100371 | TASK [Register the RHEL node] 2025-12-30 00:25:05.652809 | 2025-12-30 00:25:05.653401 | TASK [Show the subscription-manager status] 2025-12-30 00:25:06.245374 | controller | skipping: Conditional result was False 2025-12-30 00:25:06.259566 | 2025-12-30 00:25:06.259750 | TASK [Enable EPEL on RHEL] 2025-12-30 00:25:06.803994 | controller | skipping: Conditional result was False 2025-12-30 00:25:06.812309 | 2025-12-30 00:25:06.812458 | TASK [Install git and tox] 2025-12-30 00:26:31.901649 | controller | changed 2025-12-30 00:26:31.915472 | 2025-12-30 00:26:31.915606 | TASK [include_role : prepare-workspace] 2025-12-30 00:26:31.950274 | controller | ok 2025-12-30 00:26:31.991900 | 2025-12-30 00:26:31.992151 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-30 00:26:32.230385 | controller | ok 2025-12-30 00:26:32.237709 | 2025-12-30 00:26:32.237835 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-30 00:26:45.214326 | controller | Output suppressed because no_log was given 2025-12-30 00:26:45.228591 | 2025-12-30 00:26:45.228714 | TASK [include_role : prepare-workspace-openshift] 2025-12-30 00:26:45.254476 | controller | skipping: Conditional result was False 2025-12-30 00:26:45.315233 | 2025-12-30 00:26:45.315317 | PLAY [all:!appliance] 2025-12-30 00:26:45.331780 | 2025-12-30 00:26:45.331889 | TASK [Run add-build-sshkey role (RSA)] 2025-12-30 00:26:45.361902 | controller | ok 2025-12-30 00:26:45.379395 | 2025-12-30 00:26:45.379518 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-30 00:26:45.649512 | controller -> localhost | ok 2025-12-30 00:26:45.666341 | 2025-12-30 00:26:45.666597 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-30 00:26:45.691452 | controller | ok 2025-12-30 00:26:45.707330 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-30 00:26:45.714298 | 2025-12-30 00:26:45.714384 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-30 00:26:46.241109 | controller -> localhost | Generating public/private rsa key pair. 2025-12-30 00:26:46.241396 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_rsa. 2025-12-30 00:26:46.241442 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_rsa.pub. 2025-12-30 00:26:46.241475 | controller -> localhost | The key fingerprint is: 2025-12-30 00:26:46.241506 | controller -> localhost | SHA256:g5J9lLxy4uzS0+XsKVkDUYI79MuTb254IutY3K+j7jM zuul-build-sshkey 2025-12-30 00:26:46.241536 | controller -> localhost | The key's randomart image is: 2025-12-30 00:26:46.241565 | controller -> localhost | +---[RSA 2048]----+ 2025-12-30 00:26:46.241593 | controller -> localhost | | .... | 2025-12-30 00:26:46.241624 | controller -> localhost | | o..o | 2025-12-30 00:26:46.241652 | controller -> localhost | | . o+. | 2025-12-30 00:26:46.241680 | controller -> localhost | | oooo. | 2025-12-30 00:26:46.241707 | controller -> localhost | | o =oS+ | 2025-12-30 00:26:46.241748 | controller -> localhost | | = *=.+ | 2025-12-30 00:26:46.241792 | controller -> localhost | | .=..X . | 2025-12-30 00:26:46.241825 | controller -> localhost | | .+E B.B. | 2025-12-30 00:26:46.241857 | controller -> localhost | | .=BB.@= | 2025-12-30 00:26:46.241890 | controller -> localhost | +----[SHA256]-----+ 2025-12-30 00:26:46.241963 | controller -> localhost | ok: Runtime: 0:00:00.143629 2025-12-30 00:26:46.253116 | 2025-12-30 00:26:46.253255 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-30 00:26:46.290219 | controller | ok 2025-12-30 00:26:46.306477 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-30 00:26:46.320793 | 2025-12-30 00:26:46.320932 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-30 00:26:46.345753 | controller | skipping: Conditional result was False 2025-12-30 00:26:46.357467 | 2025-12-30 00:26:46.357622 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-30 00:26:46.820445 | controller | changed 2025-12-30 00:26:46.835083 | 2025-12-30 00:26:46.835255 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-30 00:26:47.050005 | controller | ok 2025-12-30 00:26:47.056407 | 2025-12-30 00:26:47.056519 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-30 00:26:47.683748 | controller | changed 2025-12-30 00:26:47.690785 | 2025-12-30 00:26:47.690921 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-30 00:26:48.293008 | controller | changed 2025-12-30 00:26:48.300599 | 2025-12-30 00:26:48.300724 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-30 00:26:48.325445 | controller | skipping: Conditional result was False 2025-12-30 00:26:48.333890 | 2025-12-30 00:26:48.334056 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-30 00:26:48.735927 | controller -> localhost | changed 2025-12-30 00:26:48.748585 | 2025-12-30 00:26:48.748692 | TASK [add-build-sshkey : Add back temp key] 2025-12-30 00:26:49.088882 | controller -> localhost | Identity added: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_rsa (zuul-build-sshkey) 2025-12-30 00:26:49.089129 | controller -> localhost | ok: Runtime: 0:00:00.012960 2025-12-30 00:26:49.095806 | 2025-12-30 00:26:49.095885 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-30 00:26:49.463765 | controller | ok 2025-12-30 00:26:49.470119 | 2025-12-30 00:26:49.470235 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-30 00:26:49.505434 | controller | skipping: Conditional result was False 2025-12-30 00:26:49.522054 | 2025-12-30 00:26:49.522201 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-30 00:26:49.558657 | controller | ok 2025-12-30 00:26:49.585331 | 2025-12-30 00:26:49.585467 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-30 00:26:49.846707 | controller -> localhost | ok 2025-12-30 00:26:49.854245 | 2025-12-30 00:26:49.854334 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-30 00:26:49.875767 | controller | ok 2025-12-30 00:26:49.887348 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-30 00:26:49.894449 | 2025-12-30 00:26:49.894522 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-30 00:26:50.194561 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-30 00:26:50.194758 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_ecdsa. 2025-12-30 00:26:50.194786 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_ecdsa.pub. 2025-12-30 00:26:50.194818 | controller -> localhost | The key fingerprint is: 2025-12-30 00:26:50.194839 | controller -> localhost | SHA256:kAGrU0M0UBd9MI3vL6y3BwS1j7clLlZPmkRiS0X9rxY zuul-build-sshkey 2025-12-30 00:26:50.194857 | controller -> localhost | The key's randomart image is: 2025-12-30 00:26:50.194874 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-30 00:26:50.194892 | controller -> localhost | | .+*.+oo=..o. | 2025-12-30 00:26:50.194908 | controller -> localhost | | . + o+.oo . | 2025-12-30 00:26:50.194925 | controller -> localhost | | + o += . . | 2025-12-30 00:26:50.194941 | controller -> localhost | | o . . oo* .| 2025-12-30 00:26:50.194957 | controller -> localhost | | o Soo * o .| 2025-12-30 00:26:50.194974 | controller -> localhost | | . o= OE .| 2025-12-30 00:26:50.194990 | controller -> localhost | | .oo= .o | 2025-12-30 00:26:50.195006 | controller -> localhost | | .+.o o | 2025-12-30 00:26:50.195059 | controller -> localhost | | .o.+ . | 2025-12-30 00:26:50.195084 | controller -> localhost | +----[SHA256]-----+ 2025-12-30 00:26:50.195136 | controller -> localhost | ok: Runtime: 0:00:00.009539 2025-12-30 00:26:50.203843 | 2025-12-30 00:26:50.203942 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-30 00:26:50.235771 | controller | ok 2025-12-30 00:26:50.244454 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-30 00:26:50.254829 | 2025-12-30 00:26:50.254942 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-30 00:26:50.280047 | controller | skipping: Conditional result was False 2025-12-30 00:26:50.289926 | 2025-12-30 00:26:50.290064 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-30 00:26:50.558783 | controller | changed 2025-12-30 00:26:50.566370 | 2025-12-30 00:26:50.566516 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-30 00:26:50.825086 | controller | ok 2025-12-30 00:26:50.832223 | 2025-12-30 00:26:50.832317 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-30 00:26:51.468897 | controller | changed 2025-12-30 00:26:51.478512 | 2025-12-30 00:26:51.478677 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-30 00:26:52.092893 | controller | changed 2025-12-30 00:26:52.110483 | 2025-12-30 00:26:52.110718 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-30 00:26:52.129427 | controller | skipping: Conditional result was False 2025-12-30 00:26:52.141800 | 2025-12-30 00:26:52.141969 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-30 00:26:52.413284 | controller -> localhost | changed 2025-12-30 00:26:52.429395 | 2025-12-30 00:26:52.429555 | TASK [add-build-sshkey : Add back temp key] 2025-12-30 00:26:52.847273 | controller -> localhost | Identity added: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/36a9a9f552704253b9bd0a3d312d984a_id_ecdsa (zuul-build-sshkey) 2025-12-30 00:26:52.847607 | controller -> localhost | ok: Runtime: 0:00:00.011718 2025-12-30 00:26:52.895432 | 2025-12-30 00:26:52.895571 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-30 00:26:53.102281 | controller | ok 2025-12-30 00:26:53.108300 | 2025-12-30 00:26:53.108386 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-30 00:26:53.145579 | controller | skipping: Conditional result was False 2025-12-30 00:26:53.159366 | 2025-12-30 00:26:53.159529 | TASK [include_role : remove-zuul-sshkey] 2025-12-30 00:26:53.185820 | controller | skipping: Conditional result was False 2025-12-30 00:26:53.195152 | 2025-12-30 00:26:53.195290 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-30 00:26:53.431966 | controller | ok: "logs" 2025-12-30 00:26:53.432247 | controller | ok: All items complete 2025-12-30 00:26:53.432276 | 2025-12-30 00:26:53.639834 | controller | ok: "artifacts" 2025-12-30 00:26:53.829953 | controller | ok: "docs" 2025-12-30 00:26:53.845674 | 2025-12-30 00:26:53.845817 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-30 00:26:54.084264 | controller | changed: "logs" 2025-12-30 00:26:54.258004 | controller | changed: "artifacts" 2025-12-30 00:26:54.439857 | controller | changed: "docs" 2025-12-30 00:26:54.513413 | 2025-12-30 00:26:54.513547 | PLAY RECAP 2025-12-30 00:26:54.513623 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-30 00:26:54.513671 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-30 00:26:54.513701 | 2025-12-30 00:26:54.679876 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-30 00:26:54.681195 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-30 00:26:55.418307 | 2025-12-30 00:26:55.418451 | PLAY [all] 2025-12-30 00:26:55.448045 | 2025-12-30 00:26:55.448195 | TASK [Install binary dependencies] 2025-12-30 00:26:55.511244 | controller | ok 2025-12-30 00:26:55.536573 | 2025-12-30 00:26:55.536830 | TASK [bindep : Include find tasks] 2025-12-30 00:26:55.570075 | controller | ok 2025-12-30 00:26:55.580303 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-30 00:26:55.588328 | 2025-12-30 00:26:55.588411 | TASK [bindep : Look for bindep.txt] 2025-12-30 00:26:56.013364 | controller | ok 2025-12-30 00:26:56.023605 | 2025-12-30 00:26:56.023763 | TASK [bindep : Define bindep_file fact] 2025-12-30 00:26:56.049964 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.056615 | 2025-12-30 00:26:56.056706 | TASK [bindep : Look for other-requirements.txt] 2025-12-30 00:26:56.260238 | controller | ok 2025-12-30 00:26:56.266489 | 2025-12-30 00:26:56.266603 | TASK [bindep : Define bindep_file fact] 2025-12-30 00:26:56.291249 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.297814 | 2025-12-30 00:26:56.297917 | TASK [bindep : Look for bindep fallback file] 2025-12-30 00:26:56.322133 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.332672 | 2025-12-30 00:26:56.332800 | TASK [bindep : Define bindep_file fact] 2025-12-30 00:26:56.357520 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.367163 | 2025-12-30 00:26:56.367304 | TASK [bindep : Include bindep tasks] 2025-12-30 00:26:56.392395 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.399070 | 2025-12-30 00:26:56.399165 | TASK [bindep : Include install tasks] 2025-12-30 00:26:56.422898 | controller | skipping: Conditional result was False 2025-12-30 00:26:56.429728 | 2025-12-30 00:26:56.429833 | LOOP [bindep : Include package tasks] 2025-12-30 00:26:56.497005 | 2025-12-30 00:26:56.497208 | TASK [Run test-setup role] 2025-12-30 00:26:56.519108 | controller | ok 2025-12-30 00:26:56.537551 | 2025-12-30 00:26:56.537699 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-30 00:26:56.742309 | controller | ok 2025-12-30 00:26:56.751296 | 2025-12-30 00:26:56.751458 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-30 00:26:57.287312 | controller | skipping: Conditional result was False 2025-12-30 00:26:57.315322 | 2025-12-30 00:26:57.315423 | PLAY RECAP 2025-12-30 00:26:57.315465 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-30 00:26:57.315486 | 2025-12-30 00:26:57.434040 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-30 00:26:57.434958 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-30 00:26:58.062105 | 2025-12-30 00:26:58.062266 | PLAY [controller] 2025-12-30 00:26:58.090836 | 2025-12-30 00:26:58.090961 | TASK [Create the /root directory] 2025-12-30 00:26:58.489531 | controller | ok 2025-12-30 00:26:58.503687 | 2025-12-30 00:26:58.503901 | TASK [Install glibc-langpack-en] 2025-12-30 00:27:02.459991 | controller | ok: Nothing to do 2025-12-30 00:27:02.465792 | 2025-12-30 00:27:02.465870 | TASK [Ensure controller directory exists] 2025-12-30 00:27:02.669522 | controller | changed 2025-12-30 00:27:02.676510 | 2025-12-30 00:27:02.676645 | TASK [Install container runtime] 2025-12-30 00:27:02.717066 | controller | ok 2025-12-30 00:27:02.755336 | 2025-12-30 00:27:02.755467 | LOOP [ensure-podman : Find distribution installation] 2025-12-30 00:27:02.779654 | controller | ok: "/var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-30 00:27:02.799515 | controller | included: /var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-30 00:27:02.808163 | 2025-12-30 00:27:02.808302 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-30 00:28:10.972130 | controller | changed 2025-12-30 00:28:10.982937 | 2025-12-30 00:28:10.983196 | TASK [ensure-podman : Fetch podman version] 2025-12-30 00:28:11.564053 | controller | Client: Podman Engine 2025-12-30 00:28:11.588905 | controller | Version: 4.6.2 2025-12-30 00:28:11.588942 | controller | API Version: 4.6.2 2025-12-30 00:28:11.588948 | controller | Go Version: go1.19.12 2025-12-30 00:28:11.588961 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-30 00:28:11.588967 | controller | OS/Arch: linux/amd64 2025-12-30 00:28:12.026408 | controller | ok: Runtime: 0:00:00.189485 2025-12-30 00:28:12.035308 | 2025-12-30 00:28:12.035430 | TASK [ensure-podman : Print podman version installed] 2025-12-30 00:28:12.067304 | Podman version: Client: Podman Engine 2025-12-30 00:28:12.067493 | Version: 4.6.2 2025-12-30 00:28:12.067530 | API Version: 4.6.2 2025-12-30 00:28:12.067557 | Go Version: go1.19.12 2025-12-30 00:28:12.067582 | Built: Mon Aug 28 19:38:31 2023 2025-12-30 00:28:12.067606 | OS/Arch: linux/amd64 2025-12-30 00:28:12.075250 | 2025-12-30 00:28:12.075329 | TASK [ensure-podman : Validate podman engine] 2025-12-30 00:28:12.608289 | controller | skipping: Conditional result was False 2025-12-30 00:28:12.621580 | 2025-12-30 00:28:12.621726 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-30 00:28:12.638847 | controller | skipping: Conditional result was False 2025-12-30 00:28:12.661903 | 2025-12-30 00:28:12.662155 | TASK [Ensure python3.8 is present] 2025-12-30 00:28:12.679621 | controller | skipping: Conditional result was False 2025-12-30 00:28:12.692910 | 2025-12-30 00:28:12.693160 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-30 00:28:12.721722 | controller | ok 2025-12-30 00:28:12.757572 | 2025-12-30 00:28:12.757723 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-30 00:28:14.316160 | controller | ok: Nothing to do 2025-12-30 00:28:14.323296 | 2025-12-30 00:28:14.323430 | TASK [our-ensure-python : Also install python3-devel] 2025-12-30 00:28:24.188422 | controller | changed 2025-12-30 00:28:24.206574 | 2025-12-30 00:28:24.206725 | TASK [Run ensure-virtualenv role] 2025-12-30 00:28:24.230961 | controller | ok 2025-12-30 00:28:24.260576 | 2025-12-30 00:28:24.260701 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-30 00:28:24.530422 | controller | /usr/bin/virtualenv 2025-12-30 00:28:24.832192 | controller | ok: Runtime: 0:00:00.005079 2025-12-30 00:28:24.840986 | 2025-12-30 00:28:24.841105 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-30 00:28:24.865060 | controller | skipping: Conditional result was False 2025-12-30 00:28:24.865373 | controller | ok: All items complete 2025-12-30 00:28:24.865414 | 2025-12-30 00:28:24.882797 | 2025-12-30 00:28:24.882983 | TASK [Find the full path of the Python interpreter] 2025-12-30 00:28:25.106935 | controller | /usr/bin/python3 2025-12-30 00:28:25.424730 | controller | ok 2025-12-30 00:28:25.434774 | 2025-12-30 00:28:25.434909 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-30 00:28:26.451293 | controller | created virtual environment CPython3.11.0.final.0-64 in 515ms 2025-12-30 00:28:26.477236 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-30 00:28:26.477272 | 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-30 00:28:26.477280 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-30 00:28:26.477293 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-30 00:28:26.514232 | controller | changed 2025-12-30 00:28:26.530514 | 2025-12-30 00:28:26.530703 | TASK [Set selinux package] 2025-12-30 00:28:26.568233 | controller | ok 2025-12-30 00:28:26.576377 | 2025-12-30 00:28:26.576505 | TASK [Set selinux package (Fedora)] 2025-12-30 00:28:26.636749 | controller | ok 2025-12-30 00:28:26.648588 | 2025-12-30 00:28:26.648835 | TASK [Install selinux into virtualenv] 2025-12-30 00:28:52.160037 | controller | Collecting selinux-please-lie-to-me 2025-12-30 00:29:04.422138 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-30 00:29:04.731783 | controller | Collecting setuptools<50.0.0 2025-12-30 00:29:04.736664 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-30 00:29:04.776277 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.8 MB/s eta 0:00:00 2025-12-30 00:29:04.853034 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-30 00:29:04.853255 | controller | Attempting uninstall: setuptools 2025-12-30 00:29:04.855708 | controller | Found existing installation: setuptools 62.6.0 2025-12-30 00:29:04.914097 | controller | Uninstalling setuptools-62.6.0: 2025-12-30 00:29:04.921977 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-30 00:29:05.266098 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-30 00:29:16.796131 | controller | 2025-12-30 00:29:16.875526 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-30 00:29:16.875566 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-30 00:29:17.232836 | controller | ok: Runtime: 0:00:49.981974 2025-12-30 00:29:17.238922 | 2025-12-30 00:29:17.238996 | TASK [Install pytest-forked into virtualenv] 2025-12-30 00:29:29.046789 | controller | Collecting pytest-forked 2025-12-30 00:29:39.241496 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-30 00:29:39.290058 | controller | Collecting py 2025-12-30 00:29:39.300927 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-30 00:29:39.316994 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 7.6 MB/s eta 0:00:00 2025-12-30 00:29:39.427388 | controller | Collecting pytest>=3.10 2025-12-30 00:29:39.431961 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-30 00:29:39.451841 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 22.2 MB/s eta 0:00:00 2025-12-30 00:29:39.491315 | controller | Collecting iniconfig>=1.0.1 2025-12-30 00:29:39.495805 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-30 00:29:39.541411 | controller | Collecting packaging>=22 2025-12-30 00:29:39.544852 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-30 00:29:39.553357 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.6 MB/s eta 0:00:00 2025-12-30 00:29:39.592395 | controller | Collecting pluggy<2,>=1.5 2025-12-30 00:29:39.596178 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-30 00:29:39.644641 | controller | Collecting pygments>=2.7.2 2025-12-30 00:29:39.648053 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-30 00:29:39.678109 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 46.7 MB/s eta 0:00:00 2025-12-30 00:29:39.748090 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-30 00:29:40.819510 | 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-30 00:29:40.828118 | controller | 2025-12-30 00:29:40.899888 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-30 00:29:40.900013 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-30 00:29:41.282609 | controller | ok: Runtime: 0:00:23.458351 2025-12-30 00:29:41.289633 | 2025-12-30 00:29:41.289708 | TASK [Update pip] 2025-12-30 00:29:41.812461 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-30 00:29:54.250882 | controller | Collecting pip 2025-12-30 00:30:06.447935 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-30 00:30:06.516072 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 28.4 MB/s eta 0:00:00 2025-12-30 00:30:06.579067 | controller | Installing collected packages: pip 2025-12-30 00:30:06.579225 | controller | Attempting uninstall: pip 2025-12-30 00:30:06.581349 | controller | Found existing installation: pip 22.2.2 2025-12-30 00:30:06.720122 | controller | Uninstalling pip-22.2.2: 2025-12-30 00:30:06.735199 | controller | Successfully uninstalled pip-22.2.2 2025-12-30 00:30:07.538198 | controller | Successfully installed pip-25.3 2025-12-30 00:30:07.834651 | controller | ok: Runtime: 0:00:26.090137 2025-12-30 00:30:07.842484 | 2025-12-30 00:30:07.842598 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-30 00:30:08.109265 | controller | changed 2025-12-30 00:30:08.114587 | 2025-12-30 00:30:08.114659 | TASK [Install ansible into virtualenv] 2025-12-30 00:30:08.609302 | controller | Processing ./src/github.com/ansible/ansible 2025-12-30 00:30:08.612560 | controller | Installing build dependencies: started 2025-12-30 00:30:55.514842 | controller | Installing build dependencies: finished with status 'done' 2025-12-30 00:30:55.516009 | controller | Getting requirements to build wheel: started 2025-12-30 00:30:56.239655 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-30 00:30:56.240994 | controller | Preparing metadata (pyproject.toml): started 2025-12-30 00:30:56.703107 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-30 00:30:56.707476 | 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-30 00:30:56.711133 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-30 00:30:57.169394 | controller | ERROR 2025-12-30 00:30:57.169519 | controller | { 2025-12-30 00:30:57.169548 | controller | "delta": "0:00:48.451491", 2025-12-30 00:30:57.169567 | controller | "end": "2025-12-30 00:30:56.773128", 2025-12-30 00:30:57.169584 | controller | "msg": "non-zero return code", 2025-12-30 00:30:57.169614 | controller | "rc": 1, 2025-12-30 00:30:57.169630 | controller | "start": "2025-12-30 00:30:08.321637" 2025-12-30 00:30:57.169646 | controller | } failure 2025-12-30 00:30:57.171443 | 2025-12-30 00:30:57.171488 | PLAY RECAP 2025-12-30 00:30:57.171527 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-30 00:30:57.171547 | 2025-12-30 00:30:57.277433 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-30 00:30:57.278428 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-30 00:30:57.912536 | 2025-12-30 00:30:57.912654 | PLAY [all] 2025-12-30 00:30:57.934772 | 2025-12-30 00:30:57.934878 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-30 00:30:58.182051 | controller | changed: non-zero return code 2025-12-30 00:30:58.189773 | 2025-12-30 00:30:58.189952 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-30 00:30:58.214834 | controller | skipping: Conditional result was False 2025-12-30 00:30:58.223154 | 2025-12-30 00:30:58.223307 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-30 00:30:58.244620 | 2025-12-30 00:30:58.244806 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-30 00:30:58.265176 | 2025-12-30 00:30:58.265330 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-30 00:30:58.279172 | controller | skipping: Conditional result was False 2025-12-30 00:30:58.288081 | 2025-12-30 00:30:58.288186 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-30 00:30:58.309500 | 2025-12-30 00:30:58.309702 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-30 00:30:58.323774 | controller | skipping: Conditional result was False 2025-12-30 00:30:58.331402 | 2025-12-30 00:30:58.331544 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-30 00:30:58.346111 | controller | skipping: Conditional result was False 2025-12-30 00:30:58.353901 | 2025-12-30 00:30:58.354042 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-30 00:30:58.368516 | controller | skipping: Conditional result was False 2025-12-30 00:30:58.399697 | 2025-12-30 00:30:58.399815 | PLAY RECAP 2025-12-30 00:30:58.399874 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-30 00:30:58.399898 | 2025-12-30 00:30:58.536532 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-30 00:30:58.537595 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-30 00:30:59.177420 | 2025-12-30 00:30:59.177547 | PLAY [all:!appliance*] 2025-12-30 00:30:59.200537 | 2025-12-30 00:30:59.200684 | TASK [unregister the node] 2025-12-30 00:30:59.731565 | controller | skipping: Conditional result was False 2025-12-30 00:30:59.744707 | 2025-12-30 00:30:59.744911 | TASK [include_role : fetch-output] 2025-12-30 00:30:59.807539 | controller | ok 2025-12-30 00:30:59.851145 | 2025-12-30 00:30:59.851293 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-30 00:30:59.907368 | controller | skipping: Conditional result was False 2025-12-30 00:30:59.917535 | 2025-12-30 00:30:59.917706 | TASK [fetch-output : Set log path for single node] 2025-12-30 00:30:59.949878 | controller | ok 2025-12-30 00:30:59.956001 | 2025-12-30 00:30:59.956143 | LOOP [fetch-output : Ensure local output dirs] 2025-12-30 00:31:00.390976 | controller -> localhost | ok: "/var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/logs" 2025-12-30 00:31:00.640758 | controller -> localhost | changed: "/var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/artifacts" 2025-12-30 00:31:00.876936 | controller -> localhost | changed: "/var/lib/zuul/builds/36a9a9f552704253b9bd0a3d312d984a/work/docs" 2025-12-30 00:31:00.895124 | 2025-12-30 00:31:00.895277 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-30 00:31:01.543936 | controller | changed: 2025-12-30 00:31:01.544220 | controller | .d..t...... ./ 2025-12-30 00:31:01.544257 | controller | cd+++++++++ controller/ 2025-12-30 00:31:01.544299 | controller | changed: All items complete 2025-12-30 00:31:01.544326 | 2025-12-30 00:31:02.021583 | controller | changed: .d..t...... ./ 2025-12-30 00:31:02.552280 | controller | changed: .d..t...... ./ 2025-12-30 00:31:02.585007 | 2025-12-30 00:31:02.585311 | TASK [include_role : fetch-output-openshift] 2025-12-30 00:31:02.624943 | controller | skipping: Conditional result was False 2025-12-30 00:31:02.633550 | 2025-12-30 00:31:02.633962 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-30 00:31:02.670528 | controller | skipping: Conditional result was False 2025-12-30 00:31:02.683116 | controller | skipping: Conditional result was False 2025-12-30 00:31:02.736467 | 2025-12-30 00:31:02.736717 | PLAY [localhost] 2025-12-30 00:31:02.750926 | 2025-12-30 00:31:02.751083 | TASK [Run Zuul manifest role] 2025-12-30 00:31:02.769709 | localhost | ok 2025-12-30 00:31:02.785663 | 2025-12-30 00:31:02.785805 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-30 00:31:03.162990 | localhost | changed 2025-12-30 00:31:03.168702 | 2025-12-30 00:31:03.168814 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-30 00:31:03.208441 | localhost | ok 2025-12-30 00:31:03.223109 | 2025-12-30 00:31:03.223259 | TASK [Set zuul-log-path fact] 2025-12-30 00:31:03.245501 | localhost | ok 2025-12-30 00:31:03.268203 | 2025-12-30 00:31:03.268346 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-30 00:31:03.300914 | localhost | ok 2025-12-30 00:31:03.314846 | 2025-12-30 00:31:03.314993 | LOOP [Run upload-logs-swift role] 2025-12-30 00:31:03.353491 | localhost | Output suppressed because no_log was given 2025-12-30 00:31:03.393994 | 2025-12-30 00:31:03.394210 | TASK [Set zuul-log-path fact] 2025-12-30 00:31:03.420856 | localhost | skipping: Conditional result was False 2025-12-30 00:31:03.426912 | 2025-12-30 00:31:03.427075 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-30 00:31:03.896031 | localhost -> localhost | ok: Runtime: 0:00:00.006587 2025-12-30 00:31:03.933757 | 2025-12-30 00:31:03.933875 | TASK [upload-logs-swift : Upload logs to swift]