2025-12-09 00:21:33.742939 | Job console starting... 2025-12-09 00:21:33.764249 | Updating repositories 2025-12-09 00:21:33.929822 | Preparing job workspace 2025-12-09 00:21:38.597824 | Running Ansible setup... 2025-12-09 00:21:43.514092 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-09 00:21:44.154680 | 2025-12-09 00:21:44.154834 | PLAY [localhost] 2025-12-09 00:21:44.163798 | 2025-12-09 00:21:44.163896 | TASK [Gathering Facts] 2025-12-09 00:21:45.111591 | localhost | ok 2025-12-09 00:21:45.127023 | 2025-12-09 00:21:45.127140 | TASK [Setup log path fact] 2025-12-09 00:21:45.145367 | localhost | ok 2025-12-09 00:21:45.158806 | 2025-12-09 00:21:45.158886 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-09 00:21:45.186796 | localhost | ok 2025-12-09 00:21:45.195315 | 2025-12-09 00:21:45.195388 | TASK [emit-job-header : Print job information] 2025-12-09 00:21:45.223442 | # Job Information 2025-12-09 00:21:45.223838 | Ansible Version: 2.15.12 2025-12-09 00:21:45.223873 | Job: ansible-test-sanity-docker-devel 2025-12-09 00:21:45.223895 | Pipeline: periodic 2025-12-09 00:21:45.223915 | Executor: ze03.softwarefactory-project.io 2025-12-09 00:21:45.223934 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-09 00:21:45.223957 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/c37/ansible/c37c0d895df74d0cbf00bce8e43fb36a/ 2025-12-09 00:21:45.223978 | Event ID: af90092fb8e9455a9ddccb9605b9ecd4 2025-12-09 00:21:45.228028 | 2025-12-09 00:21:45.228089 | LOOP [emit-job-header : Print node information] 2025-12-09 00:21:45.349670 | localhost | ok: 2025-12-09 00:21:45.349887 | localhost | # Node Information 2025-12-09 00:21:45.349915 | localhost | Inventory Hostname: controller 2025-12-09 00:21:45.349936 | localhost | Hostname: np0005551166 2025-12-09 00:21:45.349955 | localhost | Username: zuul 2025-12-09 00:21:45.349974 | localhost | Distro: Fedora 37 2025-12-09 00:21:45.349992 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-09 00:21:45.350009 | localhost | Region: ca-ymq-1 2025-12-09 00:21:45.350026 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-09 00:21:45.350042 | localhost | Product Name: OpenStack Nova 2025-12-09 00:21:45.350061 | localhost | Interface IP: 162.253.55.94 2025-12-09 00:21:45.365470 | 2025-12-09 00:21:45.365612 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-09 00:21:45.766455 | localhost -> localhost | changed 2025-12-09 00:21:45.772201 | 2025-12-09 00:21:45.772268 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-09 00:21:46.600598 | localhost -> localhost | changed 2025-12-09 00:21:46.622060 | 2025-12-09 00:21:46.622144 | PLAY [all:!appliance*] 2025-12-09 00:21:46.640784 | 2025-12-09 00:21:46.640880 | TASK [include_role : start-zuul-console] 2025-12-09 00:21:46.660391 | controller | ok 2025-12-09 00:21:46.674781 | 2025-12-09 00:21:46.674878 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-09 00:21:47.041520 | controller | ok 2025-12-09 00:21:47.053649 | 2025-12-09 00:21:47.053755 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-09 00:21:48.161359 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-09 00:21:48.171364 | 2025-12-09 00:21:48.171482 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-09 00:21:48.721048 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.729182 | 2025-12-09 00:21:48.729267 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-09 00:21:48.753676 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.765119 | 2025-12-09 00:21:48.765213 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-09 00:21:48.779978 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.789772 | 2025-12-09 00:21:48.789868 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-09 00:21:48.814825 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.824131 | 2025-12-09 00:21:48.824412 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-09 00:21:48.849585 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.858459 | 2025-12-09 00:21:48.860123 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-09 00:21:48.876527 | controller | skipping: Conditional result was False 2025-12-09 00:21:48.891418 | 2025-12-09 00:21:48.891515 | TASK [Disable Fedora Modular] 2025-12-09 00:21:49.164593 | controller | changed 2025-12-09 00:21:49.186068 | 2025-12-09 00:21:49.186250 | TASK [Enable EPEL] 2025-12-09 00:21:49.224346 | controller | skipping: Conditional result was False 2025-12-09 00:21:49.233673 | 2025-12-09 00:21:49.233815 | TASK [Register the RHEL node] 2025-12-09 00:21:49.814755 | 2025-12-09 00:21:49.815008 | TASK [Show the subscription-manager status] 2025-12-09 00:21:50.434808 | controller | skipping: Conditional result was False 2025-12-09 00:21:50.443503 | 2025-12-09 00:21:50.443569 | TASK [Enable EPEL on RHEL] 2025-12-09 00:21:50.981793 | controller | skipping: Conditional result was False 2025-12-09 00:21:50.996425 | 2025-12-09 00:21:50.996544 | TASK [Install git and tox] 2025-12-09 00:23:14.224621 | controller | changed 2025-12-09 00:23:14.231963 | 2025-12-09 00:23:14.232027 | TASK [include_role : prepare-workspace] 2025-12-09 00:23:14.251442 | controller | ok 2025-12-09 00:23:14.272334 | 2025-12-09 00:23:14.272399 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-09 00:23:14.489969 | controller | ok 2025-12-09 00:23:14.497022 | 2025-12-09 00:23:14.497172 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-09 00:23:26.514543 | controller | Output suppressed because no_log was given 2025-12-09 00:23:26.530304 | 2025-12-09 00:23:26.530420 | TASK [include_role : prepare-workspace-openshift] 2025-12-09 00:23:26.554512 | controller | skipping: Conditional result was False 2025-12-09 00:23:26.627629 | 2025-12-09 00:23:26.627749 | PLAY [all:!appliance] 2025-12-09 00:23:26.645307 | 2025-12-09 00:23:26.645368 | TASK [Run add-build-sshkey role (RSA)] 2025-12-09 00:23:26.675129 | controller | ok 2025-12-09 00:23:26.690927 | 2025-12-09 00:23:26.690991 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-09 00:23:26.938545 | controller -> localhost | ok 2025-12-09 00:23:26.945371 | 2025-12-09 00:23:26.945450 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-09 00:23:26.977718 | controller | ok 2025-12-09 00:23:26.992251 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-09 00:23:26.998477 | 2025-12-09 00:23:26.998552 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-09 00:23:27.578666 | controller -> localhost | Generating public/private rsa key pair. 2025-12-09 00:23:27.579077 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_rsa. 2025-12-09 00:23:27.579148 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_rsa.pub. 2025-12-09 00:23:27.579195 | controller -> localhost | The key fingerprint is: 2025-12-09 00:23:27.579241 | controller -> localhost | SHA256:OXLWcPwt3OjA+fj99mEqkVdGQsiAT9F2CW+Ws42ujU4 zuul-build-sshkey 2025-12-09 00:23:27.579320 | controller -> localhost | The key's randomart image is: 2025-12-09 00:23:27.579371 | controller -> localhost | +---[RSA 2048]----+ 2025-12-09 00:23:27.579413 | controller -> localhost | | .o=.+.. | 2025-12-09 00:23:27.579457 | controller -> localhost | | . o =.+.. | 2025-12-09 00:23:27.579499 | controller -> localhost | | + + .*o | 2025-12-09 00:23:27.579542 | controller -> localhost | | B +o+=o | 2025-12-09 00:23:27.579582 | controller -> localhost | | . S = *o=. | 2025-12-09 00:23:27.579639 | controller -> localhost | | + . B.o | 2025-12-09 00:23:27.579694 | controller -> localhost | | .E=. o | 2025-12-09 00:23:27.579796 | controller -> localhost | | .o+.o o| 2025-12-09 00:23:27.579851 | controller -> localhost | | .+oo.o+| 2025-12-09 00:23:27.579898 | controller -> localhost | +----[SHA256]-----+ 2025-12-09 00:23:27.579999 | controller -> localhost | ok: Runtime: 0:00:00.157732 2025-12-09 00:23:27.597524 | 2025-12-09 00:23:27.597666 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-09 00:23:27.628255 | controller | ok 2025-12-09 00:23:27.649562 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-09 00:23:27.662913 | 2025-12-09 00:23:27.663007 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-09 00:23:27.698255 | controller | skipping: Conditional result was False 2025-12-09 00:23:27.725240 | 2025-12-09 00:23:27.725379 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-09 00:23:28.188006 | controller | changed 2025-12-09 00:23:28.205327 | 2025-12-09 00:23:28.205474 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-09 00:23:28.440628 | controller | ok 2025-12-09 00:23:28.454177 | 2025-12-09 00:23:28.454316 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-09 00:23:29.157625 | controller | changed 2025-12-09 00:23:29.167481 | 2025-12-09 00:23:29.167645 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-09 00:23:29.833688 | controller | changed 2025-12-09 00:23:29.848509 | 2025-12-09 00:23:29.848654 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-09 00:23:29.875657 | controller | skipping: Conditional result was False 2025-12-09 00:23:29.892479 | 2025-12-09 00:23:29.892654 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-09 00:23:30.350148 | controller -> localhost | changed 2025-12-09 00:23:30.377425 | 2025-12-09 00:23:30.377573 | TASK [add-build-sshkey : Add back temp key] 2025-12-09 00:23:30.700810 | controller -> localhost | Identity added: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_rsa (zuul-build-sshkey) 2025-12-09 00:23:30.700994 | controller -> localhost | ok: Runtime: 0:00:00.008034 2025-12-09 00:23:30.708393 | 2025-12-09 00:23:30.708460 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-09 00:23:31.057444 | controller | ok 2025-12-09 00:23:31.066075 | 2025-12-09 00:23:31.066206 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-09 00:23:31.092798 | controller | skipping: Conditional result was False 2025-12-09 00:23:31.115345 | 2025-12-09 00:23:31.115447 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-09 00:23:31.139378 | controller | ok 2025-12-09 00:23:31.165970 | 2025-12-09 00:23:31.166115 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-09 00:23:31.436082 | controller -> localhost | ok 2025-12-09 00:23:31.443616 | 2025-12-09 00:23:31.443704 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-09 00:23:31.475425 | controller | ok 2025-12-09 00:23:31.487096 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-09 00:23:31.494485 | 2025-12-09 00:23:31.494557 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-09 00:23:31.815548 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-09 00:23:31.815869 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_ecdsa. 2025-12-09 00:23:31.815927 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_ecdsa.pub. 2025-12-09 00:23:31.815984 | controller -> localhost | The key fingerprint is: 2025-12-09 00:23:31.816027 | controller -> localhost | SHA256:dJRqjhw2oDFxkgj4sv7NlBsVHSAJpMHl1EHm1r5cmcM zuul-build-sshkey 2025-12-09 00:23:31.816067 | controller -> localhost | The key's randomart image is: 2025-12-09 00:23:31.816106 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-09 00:23:31.816145 | controller -> localhost | |=o=B==o..... | 2025-12-09 00:23:31.816182 | controller -> localhost | |o.Oo+oo ..o | 2025-12-09 00:23:31.816220 | controller -> localhost | | o = + o.o. | 2025-12-09 00:23:31.816259 | controller -> localhost | |. o . =.=.o | 2025-12-09 00:23:31.816296 | controller -> localhost | | o o OSE | 2025-12-09 00:23:31.816333 | controller -> localhost | |. * + . | 2025-12-09 00:23:31.816372 | controller -> localhost | |. + o | 2025-12-09 00:23:31.816414 | controller -> localhost | | . + o | 2025-12-09 00:23:31.816453 | controller -> localhost | | .. + | 2025-12-09 00:23:31.816488 | controller -> localhost | +----[SHA256]-----+ 2025-12-09 00:23:31.816573 | controller -> localhost | ok: Runtime: 0:00:00.016127 2025-12-09 00:23:31.832368 | 2025-12-09 00:23:31.832805 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-09 00:23:31.877218 | controller | ok 2025-12-09 00:23:31.890606 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-09 00:23:31.904561 | 2025-12-09 00:23:31.904701 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-09 00:23:31.929701 | controller | skipping: Conditional result was False 2025-12-09 00:23:31.943327 | 2025-12-09 00:23:31.943455 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-09 00:23:32.226462 | controller | changed 2025-12-09 00:23:32.245444 | 2025-12-09 00:23:32.245634 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-09 00:23:32.479439 | controller | ok 2025-12-09 00:23:32.492926 | 2025-12-09 00:23:32.493083 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-09 00:23:33.173617 | controller | changed 2025-12-09 00:23:33.186848 | 2025-12-09 00:23:33.186979 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-09 00:23:33.841878 | controller | changed 2025-12-09 00:23:33.855957 | 2025-12-09 00:23:33.856093 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-09 00:23:33.887065 | controller | skipping: Conditional result was False 2025-12-09 00:23:33.902891 | 2025-12-09 00:23:33.903039 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-09 00:23:34.207850 | controller -> localhost | changed 2025-12-09 00:23:34.263918 | 2025-12-09 00:23:34.264067 | TASK [add-build-sshkey : Add back temp key] 2025-12-09 00:23:34.574885 | controller -> localhost | Identity added: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/c37c0d895df74d0cbf00bce8e43fb36a_id_ecdsa (zuul-build-sshkey) 2025-12-09 00:23:34.575084 | controller -> localhost | ok: Runtime: 0:00:00.012614 2025-12-09 00:23:34.582778 | 2025-12-09 00:23:34.582845 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-09 00:28:36.772434 | controller | ok 2025-12-09 00:28:36.785881 | 2025-12-09 00:28:36.786014 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-09 00:28:36.823350 | controller | skipping: Conditional result was False 2025-12-09 00:28:36.849901 | 2025-12-09 00:28:36.850038 | TASK [include_role : remove-zuul-sshkey] 2025-12-09 00:28:36.878557 | controller | skipping: Conditional result was False 2025-12-09 00:28:36.893878 | 2025-12-09 00:28:36.894035 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-09 00:28:37.163520 | controller | ok: "logs" 2025-12-09 00:28:37.163985 | controller | ok: All items complete 2025-12-09 00:28:37.164045 | 2025-12-09 00:28:37.380563 | controller | ok: "artifacts" 2025-12-09 00:28:37.577060 | controller | ok: "docs" 2025-12-09 00:28:37.594381 | 2025-12-09 00:28:37.594495 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-09 00:28:37.855845 | controller | changed: "logs" 2025-12-09 00:28:38.060310 | controller | changed: "artifacts" 2025-12-09 00:28:38.268922 | controller | changed: "docs" 2025-12-09 00:28:38.319648 | 2025-12-09 00:28:38.319760 | PLAY RECAP 2025-12-09 00:28:38.319805 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-09 00:28:38.319831 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-09 00:28:38.319849 | 2025-12-09 00:28:38.435508 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-09 00:28:38.437215 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-09 00:28:39.005149 | 2025-12-09 00:28:39.005277 | PLAY [all] 2025-12-09 00:28:39.028334 | 2025-12-09 00:28:39.028459 | TASK [Install binary dependencies] 2025-12-09 00:28:39.099152 | controller | ok 2025-12-09 00:28:39.119715 | 2025-12-09 00:28:39.119858 | TASK [bindep : Include find tasks] 2025-12-09 00:28:39.149898 | controller | ok 2025-12-09 00:28:39.157974 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-09 00:28:39.164552 | 2025-12-09 00:28:39.164615 | TASK [bindep : Look for bindep.txt] 2025-12-09 00:28:39.742901 | controller | ok 2025-12-09 00:28:39.757495 | 2025-12-09 00:28:39.757672 | TASK [bindep : Define bindep_file fact] 2025-12-09 00:28:39.775459 | controller | skipping: Conditional result was False 2025-12-09 00:28:39.789547 | 2025-12-09 00:28:39.789721 | TASK [bindep : Look for other-requirements.txt] 2025-12-09 00:28:40.013103 | controller | ok 2025-12-09 00:28:40.025904 | 2025-12-09 00:28:40.026059 | TASK [bindep : Define bindep_file fact] 2025-12-09 00:28:40.063228 | controller | skipping: Conditional result was False 2025-12-09 00:28:40.072908 | 2025-12-09 00:28:40.073026 | TASK [bindep : Look for bindep fallback file] 2025-12-09 00:28:40.109833 | controller | skipping: Conditional result was False 2025-12-09 00:28:40.119898 | 2025-12-09 00:28:40.119994 | TASK [bindep : Define bindep_file fact] 2025-12-09 00:28:40.144938 | controller | skipping: Conditional result was False 2025-12-09 00:28:40.154695 | 2025-12-09 00:28:40.154848 | TASK [bindep : Include bindep tasks] 2025-12-09 00:28:40.181214 | controller | skipping: Conditional result was False 2025-12-09 00:28:40.191307 | 2025-12-09 00:28:40.191417 | TASK [bindep : Include install tasks] 2025-12-09 00:28:40.216630 | controller | skipping: Conditional result was False 2025-12-09 00:28:40.226396 | 2025-12-09 00:28:40.226515 | LOOP [bindep : Include package tasks] 2025-12-09 00:28:40.300446 | 2025-12-09 00:28:40.300659 | TASK [Run test-setup role] 2025-12-09 00:28:40.327604 | controller | ok 2025-12-09 00:28:40.364760 | 2025-12-09 00:28:40.364887 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-09 00:28:40.569975 | controller | ok 2025-12-09 00:28:40.576353 | 2025-12-09 00:28:40.576418 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-09 00:28:41.110383 | controller | skipping: Conditional result was False 2025-12-09 00:28:41.168327 | 2025-12-09 00:28:41.168420 | PLAY RECAP 2025-12-09 00:28:41.168475 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-09 00:28:41.168505 | 2025-12-09 00:28:41.276308 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-09 00:28:41.277166 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-09 00:28:41.860619 | 2025-12-09 00:28:41.860776 | PLAY [controller] 2025-12-09 00:28:41.882483 | 2025-12-09 00:28:41.882599 | TASK [Create the /root directory] 2025-12-09 00:28:42.452176 | controller | ok 2025-12-09 00:28:42.459236 | 2025-12-09 00:28:42.459322 | TASK [Install glibc-langpack-en] 2025-12-09 00:28:46.517928 | controller | ok: Nothing to do 2025-12-09 00:28:46.531131 | 2025-12-09 00:28:46.531272 | TASK [Ensure controller directory exists] 2025-12-09 00:28:46.783687 | controller | changed 2025-12-09 00:28:46.796397 | 2025-12-09 00:28:46.796528 | TASK [Install container runtime] 2025-12-09 00:28:46.854894 | controller | ok 2025-12-09 00:28:46.911031 | 2025-12-09 00:28:46.911178 | LOOP [ensure-podman : Find distribution installation] 2025-12-09 00:28:46.954190 | controller | ok: "/var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-09 00:28:46.963286 | controller | included: /var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-09 00:28:46.969805 | 2025-12-09 00:28:46.969867 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-09 00:29:50.758303 | controller | changed 2025-12-09 00:29:50.774166 | 2025-12-09 00:29:50.774291 | TASK [ensure-podman : Fetch podman version] 2025-12-09 00:29:51.314736 | controller | Client: Podman Engine 2025-12-09 00:29:51.314828 | controller | Version: 4.6.2 2025-12-09 00:29:51.314873 | controller | API Version: 4.6.2 2025-12-09 00:29:51.314914 | controller | Go Version: go1.19.12 2025-12-09 00:29:51.314967 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-09 00:29:51.315009 | controller | OS/Arch: linux/amd64 2025-12-09 00:29:51.820315 | controller | ok: Runtime: 0:00:00.187353 2025-12-09 00:29:51.830044 | 2025-12-09 00:29:51.830150 | TASK [ensure-podman : Print podman version installed] 2025-12-09 00:29:51.853207 | Podman version: Client: Podman Engine 2025-12-09 00:29:51.853385 | Version: 4.6.2 2025-12-09 00:29:51.853423 | API Version: 4.6.2 2025-12-09 00:29:51.853452 | Go Version: go1.19.12 2025-12-09 00:29:51.853476 | Built: Mon Aug 28 19:38:31 2023 2025-12-09 00:29:51.853503 | OS/Arch: linux/amd64 2025-12-09 00:29:51.861675 | 2025-12-09 00:29:51.861779 | TASK [ensure-podman : Validate podman engine] 2025-12-09 00:29:52.401255 | controller | skipping: Conditional result was False 2025-12-09 00:29:52.419084 | 2025-12-09 00:29:52.419307 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-09 00:29:52.446843 | controller | skipping: Conditional result was False 2025-12-09 00:29:52.464167 | 2025-12-09 00:29:52.464274 | TASK [Ensure python3.8 is present] 2025-12-09 00:29:52.488948 | controller | skipping: Conditional result was False 2025-12-09 00:29:52.500613 | 2025-12-09 00:29:52.500698 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-09 00:29:52.524435 | controller | ok 2025-12-09 00:29:52.550983 | 2025-12-09 00:29:52.551064 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-09 00:29:53.967800 | controller | ok: Nothing to do 2025-12-09 00:29:53.981585 | 2025-12-09 00:29:53.981778 | TASK [our-ensure-python : Also install python3-devel] 2025-12-09 00:30:02.461167 | controller | changed 2025-12-09 00:30:02.479800 | 2025-12-09 00:30:02.479967 | TASK [Run ensure-virtualenv role] 2025-12-09 00:30:02.504128 | controller | ok 2025-12-09 00:30:02.537085 | 2025-12-09 00:30:02.537240 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-09 00:30:02.747563 | controller | /usr/bin/virtualenv 2025-12-09 00:30:03.070370 | controller | ok: Runtime: 0:00:00.005036 2025-12-09 00:30:03.084578 | 2025-12-09 00:30:03.084720 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-09 00:30:03.120007 | controller | skipping: Conditional result was False 2025-12-09 00:30:03.120464 | controller | ok: All items complete 2025-12-09 00:30:03.120525 | 2025-12-09 00:30:03.147153 | 2025-12-09 00:30:03.147355 | TASK [Find the full path of the Python interpreter] 2025-12-09 00:30:03.401965 | controller | /usr/bin/python3 2025-12-09 00:30:03.718826 | controller | ok 2025-12-09 00:30:03.732114 | 2025-12-09 00:30:03.732250 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-09 00:30:04.499821 | controller | created virtual environment CPython3.11.0.final.0-64 in 461ms 2025-12-09 00:30:04.516227 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-09 00:30:04.516266 | 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-09 00:30:04.516275 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-09 00:30:04.516290 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-09 00:30:04.790513 | controller | changed 2025-12-09 00:30:04.806159 | 2025-12-09 00:30:04.806310 | TASK [Set selinux package] 2025-12-09 00:30:04.839103 | controller | ok 2025-12-09 00:30:04.852033 | 2025-12-09 00:30:04.852173 | TASK [Set selinux package (Fedora)] 2025-12-09 00:30:04.888052 | controller | ok 2025-12-09 00:30:04.896120 | 2025-12-09 00:30:04.896210 | TASK [Install selinux into virtualenv] 2025-12-09 00:30:06.116896 | controller | Collecting selinux-please-lie-to-me 2025-12-09 00:30:06.170894 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-09 00:30:06.503499 | controller | Collecting setuptools<50.0.0 2025-12-09 00:30:06.545993 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-09 00:30:06.590087 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.3 MB/s eta 0:00:00 2025-12-09 00:30:06.672154 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-09 00:30:06.672364 | controller | Attempting uninstall: setuptools 2025-12-09 00:30:06.674751 | controller | Found existing installation: setuptools 62.6.0 2025-12-09 00:30:06.733840 | controller | Uninstalling setuptools-62.6.0: 2025-12-09 00:30:06.741730 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-09 00:30:07.103931 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-09 00:30:07.222412 | controller | 2025-12-09 00:30:07.300527 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-09 00:30:07.300569 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-09 00:30:07.447398 | controller | ok: Runtime: 0:00:02.191272 2025-12-09 00:30:07.463576 | 2025-12-09 00:30:07.463800 | TASK [Install pytest-forked into virtualenv] 2025-12-09 00:30:08.060179 | controller | Collecting pytest-forked 2025-12-09 00:30:08.104853 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-09 00:30:08.158338 | controller | Collecting py 2025-12-09 00:30:08.183254 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-09 00:30:08.203766 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.2 MB/s eta 0:00:00 2025-12-09 00:30:08.363390 | controller | Collecting pytest>=3.10 2025-12-09 00:30:08.377409 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-09 00:30:08.393524 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.9 MB/s eta 0:00:00 2025-12-09 00:30:08.463990 | controller | Collecting iniconfig>=1.0.1 2025-12-09 00:30:08.468160 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-09 00:30:08.515770 | controller | Collecting packaging>=22 2025-12-09 00:30:08.520759 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-09 00:30:08.528771 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.5 MB/s eta 0:00:00 2025-12-09 00:30:08.569380 | controller | Collecting pluggy<2,>=1.5 2025-12-09 00:30:08.572723 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-09 00:30:08.629106 | controller | Collecting pygments>=2.7.2 2025-12-09 00:30:08.633731 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-09 00:30:08.656080 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 60.7 MB/s eta 0:00:00 2025-12-09 00:30:08.721111 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-09 00:30:09.876858 | 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-09 00:30:09.885715 | controller | 2025-12-09 00:30:09.954690 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-09 00:30:09.954734 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-09 00:30:10.024474 | controller | ok: Runtime: 0:00:02.256979 2025-12-09 00:30:10.038836 | 2025-12-09 00:30:10.039029 | TASK [Update pip] 2025-12-09 00:30:10.543988 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-09 00:30:10.669225 | controller | Collecting pip 2025-12-09 00:30:10.740972 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-09 00:30:10.789063 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.3 MB/s eta 0:00:00 2025-12-09 00:30:10.854408 | controller | Installing collected packages: pip 2025-12-09 00:30:10.854619 | controller | Attempting uninstall: pip 2025-12-09 00:30:10.857085 | controller | Found existing installation: pip 22.2.2 2025-12-09 00:30:10.993854 | controller | Uninstalling pip-22.2.2: 2025-12-09 00:30:11.008754 | controller | Successfully uninstalled pip-22.2.2 2025-12-09 00:30:11.839058 | controller | Successfully installed pip-25.3 2025-12-09 00:30:12.104942 | controller | ok: Runtime: 0:00:01.655323 2025-12-09 00:30:12.119534 | 2025-12-09 00:30:12.119665 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-09 00:30:12.333413 | controller | changed 2025-12-09 00:30:12.347676 | 2025-12-09 00:30:12.347884 | TASK [Install ansible into virtualenv] 2025-12-09 00:30:12.879860 | controller | Processing ./src/github.com/ansible/ansible 2025-12-09 00:30:12.883148 | controller | Installing build dependencies: started 2025-12-09 00:30:13.788658 | controller | Installing build dependencies: finished with status 'done' 2025-12-09 00:30:14.517045 | controller | Getting requirements to build wheel: started 2025-12-09 00:30:14.517095 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-09 00:30:14.966775 | controller | Preparing metadata (pyproject.toml): started 2025-12-09 00:30:14.966821 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-09 00:30:14.971661 | 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-09 00:30:14.972088 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-09 00:30:15.440476 | controller | ERROR 2025-12-09 00:30:15.440710 | controller | { 2025-12-09 00:30:15.440783 | controller | "delta": "0:00:02.430706", 2025-12-09 00:30:15.440812 | controller | "end": "2025-12-09 00:30:15.033462", 2025-12-09 00:30:15.440836 | controller | "msg": "non-zero return code", 2025-12-09 00:30:15.440879 | controller | "rc": 1, 2025-12-09 00:30:15.440906 | controller | "start": "2025-12-09 00:30:12.602756" 2025-12-09 00:30:15.440929 | controller | } failure 2025-12-09 00:30:15.443516 | 2025-12-09 00:30:15.443584 | PLAY RECAP 2025-12-09 00:30:15.443640 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-09 00:30:15.443663 | 2025-12-09 00:30:15.642383 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-09 00:30:15.643389 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-09 00:30:16.265957 | 2025-12-09 00:30:16.266066 | PLAY [all] 2025-12-09 00:30:16.287740 | 2025-12-09 00:30:16.287820 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-09 00:30:16.683621 | controller | changed: non-zero return code 2025-12-09 00:30:16.696712 | 2025-12-09 00:30:16.696900 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-09 00:30:16.716110 | controller | skipping: Conditional result was False 2025-12-09 00:30:16.726933 | 2025-12-09 00:30:16.727073 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-09 00:30:16.772024 | 2025-12-09 00:30:16.772331 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-09 00:30:16.813478 | 2025-12-09 00:30:16.813674 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-09 00:30:16.839601 | controller | skipping: Conditional result was False 2025-12-09 00:30:16.851833 | 2025-12-09 00:30:16.851940 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-09 00:30:16.888121 | 2025-12-09 00:30:16.888316 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-09 00:30:16.914251 | controller | skipping: Conditional result was False 2025-12-09 00:30:16.924752 | 2025-12-09 00:30:16.924851 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-09 00:30:16.950370 | controller | skipping: Conditional result was False 2025-12-09 00:30:16.960076 | 2025-12-09 00:30:16.960163 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-09 00:30:16.986708 | controller | skipping: Conditional result was False 2025-12-09 00:30:17.034619 | 2025-12-09 00:30:17.034710 | PLAY RECAP 2025-12-09 00:30:17.034868 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-09 00:30:17.034903 | 2025-12-09 00:30:17.176603 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-09 00:30:17.177505 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-09 00:30:17.820013 | 2025-12-09 00:30:17.820240 | PLAY [all:!appliance*] 2025-12-09 00:30:17.844547 | 2025-12-09 00:30:17.844704 | TASK [unregister the node] 2025-12-09 00:30:18.379995 | controller | skipping: Conditional result was False 2025-12-09 00:30:18.390455 | 2025-12-09 00:30:18.390577 | TASK [include_role : fetch-output] 2025-12-09 00:30:18.437503 | controller | ok 2025-12-09 00:30:18.476084 | 2025-12-09 00:30:18.476344 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-09 00:30:18.533488 | controller | skipping: Conditional result was False 2025-12-09 00:30:18.543267 | 2025-12-09 00:30:18.543364 | TASK [fetch-output : Set log path for single node] 2025-12-09 00:30:18.576656 | controller | ok 2025-12-09 00:30:18.589040 | 2025-12-09 00:30:18.589195 | LOOP [fetch-output : Ensure local output dirs] 2025-12-09 00:30:19.078623 | controller -> localhost | ok: "/var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/logs" 2025-12-09 00:30:19.346192 | controller -> localhost | changed: "/var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/artifacts" 2025-12-09 00:30:19.629621 | controller -> localhost | changed: "/var/lib/zuul/builds/c37c0d895df74d0cbf00bce8e43fb36a/work/docs" 2025-12-09 00:30:19.648436 | 2025-12-09 00:30:19.648575 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-09 00:30:20.396087 | controller | changed: 2025-12-09 00:30:20.396679 | controller | .d..t...... ./ 2025-12-09 00:30:20.396841 | controller | cd+++++++++ controller/ 2025-12-09 00:30:20.396998 | controller | changed: All items complete 2025-12-09 00:30:20.397099 | 2025-12-09 00:30:20.926076 | controller | changed: .d..t...... ./ 2025-12-09 00:30:21.430210 | controller | changed: .d..t...... ./ 2025-12-09 00:30:21.455629 | 2025-12-09 00:30:21.455804 | TASK [include_role : fetch-output-openshift] 2025-12-09 00:30:21.482221 | controller | skipping: Conditional result was False 2025-12-09 00:30:21.492826 | 2025-12-09 00:30:21.492949 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-09 00:30:21.525148 | controller | skipping: Conditional result was False 2025-12-09 00:30:21.538149 | controller | skipping: Conditional result was False 2025-12-09 00:30:21.568513 | 2025-12-09 00:30:21.568616 | PLAY [localhost] 2025-12-09 00:30:21.581745 | 2025-12-09 00:30:21.581913 | TASK [Run Zuul manifest role] 2025-12-09 00:30:21.600234 | localhost | ok 2025-12-09 00:30:21.615363 | 2025-12-09 00:30:21.615455 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-09 00:30:21.999360 | localhost | changed 2025-12-09 00:30:22.004806 | 2025-12-09 00:30:22.004872 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-09 00:30:22.034175 | localhost | ok 2025-12-09 00:30:22.042335 | 2025-12-09 00:30:22.042394 | TASK [Set zuul-log-path fact] 2025-12-09 00:30:22.059898 | localhost | ok 2025-12-09 00:30:22.073979 | 2025-12-09 00:30:22.074043 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-09 00:30:22.101620 | localhost | ok 2025-12-09 00:30:22.109520 | 2025-12-09 00:30:22.109575 | LOOP [Run upload-logs-swift role] 2025-12-09 00:30:22.133225 | localhost | Output suppressed because no_log was given 2025-12-09 00:30:22.157141 | 2025-12-09 00:30:22.157202 | TASK [Set zuul-log-path fact] 2025-12-09 00:30:22.180958 | localhost | skipping: Conditional result was False 2025-12-09 00:30:22.186104 | 2025-12-09 00:30:22.186168 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-09 00:30:22.628900 | localhost -> localhost | ok: Runtime: 0:00:00.005934 2025-12-09 00:30:22.659037 | 2025-12-09 00:30:22.659161 | TASK [upload-logs-swift : Upload logs to swift]