2025-12-12 00:14:24.074738 | Job console starting... 2025-12-12 00:14:24.139747 | Updating repositories 2025-12-12 00:14:24.266448 | Preparing job workspace 2025-12-12 00:14:27.775869 | Running Ansible setup... 2025-12-12 00:14:32.586982 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-12 00:14:33.210288 | 2025-12-12 00:14:33.210408 | PLAY [localhost] 2025-12-12 00:14:33.218574 | 2025-12-12 00:14:33.218643 | TASK [Gathering Facts] 2025-12-12 00:14:34.212565 | localhost | ok 2025-12-12 00:14:34.234221 | 2025-12-12 00:14:34.234379 | TASK [Setup log path fact] 2025-12-12 00:14:34.254791 | localhost | ok 2025-12-12 00:14:34.272841 | 2025-12-12 00:14:34.273101 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-12 00:14:34.305500 | localhost | ok 2025-12-12 00:14:34.317442 | 2025-12-12 00:14:34.317531 | TASK [emit-job-header : Print job information] 2025-12-12 00:14:34.345104 | # Job Information 2025-12-12 00:14:34.345247 | Ansible Version: 2.15.12 2025-12-12 00:14:34.345279 | Job: ansible-test-sanity-docker-devel 2025-12-12 00:14:34.345424 | Pipeline: periodic 2025-12-12 00:14:34.345459 | Executor: ze01.softwarefactory-project.io 2025-12-12 00:14:34.345479 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-12 00:14:34.345500 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/7ec/ansible/7ec0e3e9cacb4c558fc7e7a3127d0846/ 2025-12-12 00:14:34.345519 | Event ID: 336ce9c82f5d4f159df4daaad304a8e0 2025-12-12 00:14:34.349314 | 2025-12-12 00:14:34.349402 | LOOP [emit-job-header : Print node information] 2025-12-12 00:14:34.448168 | localhost | ok: 2025-12-12 00:14:34.448362 | localhost | # Node Information 2025-12-12 00:14:34.448390 | localhost | Inventory Hostname: controller 2025-12-12 00:14:34.448410 | localhost | Hostname: np0005556176 2025-12-12 00:14:34.448428 | localhost | Username: zuul 2025-12-12 00:14:34.448449 | localhost | Distro: Fedora 37 2025-12-12 00:14:34.448467 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-12 00:14:34.448484 | localhost | Region: ca-ymq-1 2025-12-12 00:14:34.448501 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-12 00:14:34.448517 | localhost | Product Name: OpenStack Nova 2025-12-12 00:14:34.448533 | localhost | Interface IP: 162.253.55.49 2025-12-12 00:14:34.470526 | 2025-12-12 00:14:34.470721 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-12 00:14:34.896031 | localhost -> localhost | changed 2025-12-12 00:14:34.904212 | 2025-12-12 00:14:34.904307 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-12 00:14:35.811037 | localhost -> localhost | changed 2025-12-12 00:14:35.837346 | 2025-12-12 00:14:35.837454 | PLAY [all:!appliance*] 2025-12-12 00:14:35.861093 | 2025-12-12 00:14:35.861169 | TASK [include_role : start-zuul-console] 2025-12-12 00:14:35.880443 | controller | ok 2025-12-12 00:14:35.895526 | 2025-12-12 00:14:35.895615 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-12 00:14:36.376542 | controller | ok 2025-12-12 00:14:36.397532 | 2025-12-12 00:14:36.397677 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-12 00:14:37.203274 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-12 00:14:37.215987 | 2025-12-12 00:14:37.216143 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-12 00:14:37.757568 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.772415 | 2025-12-12 00:14:37.772579 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-12 00:14:37.800483 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.815726 | 2025-12-12 00:14:37.815883 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-12 00:14:37.842340 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.856510 | 2025-12-12 00:14:37.856662 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-12 00:14:37.883289 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.897706 | 2025-12-12 00:14:37.897862 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-12 00:14:37.924438 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.938967 | 2025-12-12 00:14:37.939150 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-12 00:14:37.966203 | controller | skipping: Conditional result was False 2025-12-12 00:14:37.994361 | 2025-12-12 00:14:37.994493 | TASK [Disable Fedora Modular] 2025-12-12 00:14:38.256986 | controller | changed 2025-12-12 00:14:38.269999 | 2025-12-12 00:14:38.270202 | TASK [Enable EPEL] 2025-12-12 00:14:38.297649 | controller | skipping: Conditional result was False 2025-12-12 00:14:38.311751 | 2025-12-12 00:14:38.311899 | TASK [Register the RHEL node] 2025-12-12 00:14:38.878274 | 2025-12-12 00:14:38.878541 | TASK [Show the subscription-manager status] 2025-12-12 00:14:39.472070 | controller | skipping: Conditional result was False 2025-12-12 00:14:39.493597 | 2025-12-12 00:14:39.493824 | TASK [Enable EPEL on RHEL] 2025-12-12 00:14:40.057056 | controller | skipping: Conditional result was False 2025-12-12 00:14:40.067078 | 2025-12-12 00:14:40.067208 | TASK [Install git and tox] 2025-12-12 00:16:01.614974 | controller | changed 2025-12-12 00:16:01.622273 | 2025-12-12 00:16:01.622558 | TASK [include_role : prepare-workspace] 2025-12-12 00:16:01.654478 | controller | ok 2025-12-12 00:16:01.680739 | 2025-12-12 00:16:01.681074 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-12 00:16:01.929817 | controller | ok 2025-12-12 00:16:01.942965 | 2025-12-12 00:16:01.943498 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-12 00:16:14.182107 | controller | Output suppressed because no_log was given 2025-12-12 00:16:14.192167 | 2025-12-12 00:16:14.192238 | TASK [include_role : prepare-workspace-openshift] 2025-12-12 00:16:14.216055 | controller | skipping: Conditional result was False 2025-12-12 00:16:14.268271 | 2025-12-12 00:16:14.268344 | PLAY [all:!appliance] 2025-12-12 00:16:14.285076 | 2025-12-12 00:16:14.285176 | TASK [Run add-build-sshkey role (RSA)] 2025-12-12 00:16:14.305715 | controller | ok 2025-12-12 00:16:14.322615 | 2025-12-12 00:16:14.322727 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-12 00:16:14.580451 | controller -> localhost | ok 2025-12-12 00:16:14.587086 | 2025-12-12 00:16:14.587152 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-12 00:16:14.606879 | controller | ok 2025-12-12 00:16:14.620813 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-12 00:16:14.627451 | 2025-12-12 00:16:14.627514 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-12 00:16:15.288009 | controller -> localhost | Generating public/private rsa key pair. 2025-12-12 00:16:15.288252 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_rsa. 2025-12-12 00:16:15.288285 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_rsa.pub. 2025-12-12 00:16:15.288310 | controller -> localhost | The key fingerprint is: 2025-12-12 00:16:15.288333 | controller -> localhost | SHA256:ihtR9UzO4dbK9yMvzY28QynsHXZ+a9xjzhy7cYssDmw zuul-build-sshkey 2025-12-12 00:16:15.288356 | controller -> localhost | The key's randomart image is: 2025-12-12 00:16:15.288378 | controller -> localhost | +---[RSA 2048]----+ 2025-12-12 00:16:15.288400 | controller -> localhost | | . o | 2025-12-12 00:16:15.288423 | controller -> localhost | | . B o | 2025-12-12 00:16:15.288445 | controller -> localhost | | . B . | 2025-12-12 00:16:15.288466 | controller -> localhost | | . o . | 2025-12-12 00:16:15.288487 | controller -> localhost | | . S o.. . | 2025-12-12 00:16:15.288521 | controller -> localhost | | o .. .o.= .| 2025-12-12 00:16:15.288550 | controller -> localhost | | o . E ..O+Oo| 2025-12-12 00:16:15.288576 | controller -> localhost | | o . ..+o@*@| 2025-12-12 00:16:15.288602 | controller -> localhost | | . ...+*@=| 2025-12-12 00:16:15.288630 | controller -> localhost | +----[SHA256]-----+ 2025-12-12 00:16:15.288690 | controller -> localhost | ok: Runtime: 0:00:00.199440 2025-12-12 00:16:15.297116 | 2025-12-12 00:16:15.297249 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-12 00:16:15.329587 | controller | ok 2025-12-12 00:16:15.342726 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-12 00:16:15.352995 | 2025-12-12 00:16:15.353134 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-12 00:16:15.377908 | controller | skipping: Conditional result was False 2025-12-12 00:16:15.386381 | 2025-12-12 00:16:15.386496 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-12 00:16:15.892763 | controller | changed 2025-12-12 00:16:15.906090 | 2025-12-12 00:16:15.906228 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-12 00:16:16.151065 | controller | ok 2025-12-12 00:16:16.164960 | 2025-12-12 00:16:16.165233 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-12 00:16:16.830802 | controller | changed 2025-12-12 00:16:16.844535 | 2025-12-12 00:16:16.844708 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-12 00:16:17.536331 | controller | changed 2025-12-12 00:16:17.545338 | 2025-12-12 00:16:17.545451 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-12 00:16:17.570342 | controller | skipping: Conditional result was False 2025-12-12 00:16:17.580548 | 2025-12-12 00:16:17.580666 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-12 00:16:17.965609 | controller -> localhost | changed 2025-12-12 00:16:17.979117 | 2025-12-12 00:16:17.979230 | TASK [add-build-sshkey : Add back temp key] 2025-12-12 00:16:18.226916 | controller -> localhost | Identity added: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_rsa (zuul-build-sshkey) 2025-12-12 00:16:18.227172 | controller -> localhost | ok: Runtime: 0:00:00.006825 2025-12-12 00:16:18.234854 | 2025-12-12 00:16:18.234945 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-12 00:16:18.620046 | controller | ok 2025-12-12 00:16:18.626618 | 2025-12-12 00:16:18.626686 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-12 00:16:18.673424 | controller | skipping: Conditional result was False 2025-12-12 00:16:18.692403 | 2025-12-12 00:16:18.692510 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-12 00:16:18.723405 | controller | ok 2025-12-12 00:16:18.749540 | 2025-12-12 00:16:18.749646 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-12 00:16:19.030438 | controller -> localhost | ok 2025-12-12 00:16:19.042399 | 2025-12-12 00:16:19.042517 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-12 00:16:19.083709 | controller | ok 2025-12-12 00:16:19.095982 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-12 00:16:19.104644 | 2025-12-12 00:16:19.104739 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-12 00:16:19.384877 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-12 00:16:19.385097 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_ecdsa. 2025-12-12 00:16:19.385135 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_ecdsa.pub. 2025-12-12 00:16:19.385174 | controller -> localhost | The key fingerprint is: 2025-12-12 00:16:19.385199 | controller -> localhost | SHA256:GeNaBegtBCt0Noxn0cAIGFDNLaoeiXwcGEqhygieQ6M zuul-build-sshkey 2025-12-12 00:16:19.385223 | controller -> localhost | The key's randomart image is: 2025-12-12 00:16:19.385249 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-12 00:16:19.385275 | controller -> localhost | |*=+BB* .. | 2025-12-12 00:16:19.385300 | controller -> localhost | |o+ooOo= . | 2025-12-12 00:16:19.385324 | controller -> localhost | |=o++.+ .o . | 2025-12-12 00:16:19.385349 | controller -> localhost | |X.+o o..= | 2025-12-12 00:16:19.385374 | controller -> localhost | |E*o . .S | 2025-12-12 00:16:19.385399 | controller -> localhost | |o+.o o | 2025-12-12 00:16:19.385422 | controller -> localhost | |. o . | 2025-12-12 00:16:19.385443 | controller -> localhost | | . | 2025-12-12 00:16:19.385460 | controller -> localhost | | | 2025-12-12 00:16:19.385478 | controller -> localhost | +----[SHA256]-----+ 2025-12-12 00:16:19.385525 | controller -> localhost | ok: Runtime: 0:00:00.007812 2025-12-12 00:16:19.393122 | 2025-12-12 00:16:19.393236 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-12 00:16:19.414882 | controller | ok 2025-12-12 00:16:19.423103 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-12 00:16:19.432369 | 2025-12-12 00:16:19.432455 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-12 00:16:19.456853 | controller | skipping: Conditional result was False 2025-12-12 00:16:19.465965 | 2025-12-12 00:16:19.466089 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-12 00:16:19.735198 | controller | changed 2025-12-12 00:16:19.743997 | 2025-12-12 00:16:19.744127 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-12 00:16:19.992684 | controller | ok 2025-12-12 00:16:20.008446 | 2025-12-12 00:16:20.008614 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-12 00:16:20.712931 | controller | changed 2025-12-12 00:16:20.730450 | 2025-12-12 00:16:20.730633 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-12 00:16:21.448656 | controller | changed 2025-12-12 00:16:21.464078 | 2025-12-12 00:16:21.464203 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-12 00:16:21.500124 | controller | skipping: Conditional result was False 2025-12-12 00:16:21.511466 | 2025-12-12 00:16:21.511599 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-12 00:16:21.772916 | controller -> localhost | changed 2025-12-12 00:16:21.785785 | 2025-12-12 00:16:21.785884 | TASK [add-build-sshkey : Add back temp key] 2025-12-12 00:16:22.105632 | controller -> localhost | Identity added: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/7ec0e3e9cacb4c558fc7e7a3127d0846_id_ecdsa (zuul-build-sshkey) 2025-12-12 00:16:22.105830 | controller -> localhost | ok: Runtime: 0:00:00.007186 2025-12-12 00:16:22.115502 | 2025-12-12 00:16:22.115617 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-12 00:16:22.373853 | controller | ok 2025-12-12 00:16:22.381982 | 2025-12-12 00:16:22.382089 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-12 00:16:22.408868 | controller | skipping: Conditional result was False 2025-12-12 00:16:22.425811 | 2025-12-12 00:16:22.425906 | TASK [include_role : remove-zuul-sshkey] 2025-12-12 00:16:22.452712 | controller | skipping: Conditional result was False 2025-12-12 00:16:22.462970 | 2025-12-12 00:16:22.463111 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-12 00:16:22.720961 | controller | ok: "logs" 2025-12-12 00:16:22.721568 | controller | ok: All items complete 2025-12-12 00:16:22.721650 | 2025-12-12 00:16:22.924689 | controller | ok: "artifacts" 2025-12-12 00:16:23.132222 | controller | ok: "docs" 2025-12-12 00:16:23.146917 | 2025-12-12 00:16:23.147079 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-12 00:16:23.401109 | controller | changed: "logs" 2025-12-12 00:16:23.595739 | controller | changed: "artifacts" 2025-12-12 00:16:23.802837 | controller | changed: "docs" 2025-12-12 00:16:23.872830 | 2025-12-12 00:16:23.872957 | PLAY RECAP 2025-12-12 00:16:23.873224 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-12 00:16:23.873264 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-12 00:16:23.873291 | 2025-12-12 00:16:24.027877 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-12 00:16:24.029265 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-12 00:16:24.652379 | 2025-12-12 00:16:24.652506 | PLAY [all] 2025-12-12 00:16:24.676722 | 2025-12-12 00:16:24.676873 | TASK [Install binary dependencies] 2025-12-12 00:16:24.717339 | controller | ok 2025-12-12 00:16:24.738057 | 2025-12-12 00:16:24.738181 | TASK [bindep : Include find tasks] 2025-12-12 00:16:24.768350 | controller | ok 2025-12-12 00:16:24.776761 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-12 00:16:24.783446 | 2025-12-12 00:16:24.783524 | TASK [bindep : Look for bindep.txt] 2025-12-12 00:21:28.336495 | controller | ok 2025-12-12 00:21:28.349751 | 2025-12-12 00:21:28.349931 | TASK [bindep : Define bindep_file fact] 2025-12-12 00:21:28.388338 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.395912 | 2025-12-12 00:21:28.396071 | TASK [bindep : Look for other-requirements.txt] 2025-12-12 00:21:28.624625 | controller | ok 2025-12-12 00:21:28.630316 | 2025-12-12 00:21:28.630388 | TASK [bindep : Define bindep_file fact] 2025-12-12 00:21:28.665412 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.672136 | 2025-12-12 00:21:28.672209 | TASK [bindep : Look for bindep fallback file] 2025-12-12 00:21:28.696154 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.702725 | 2025-12-12 00:21:28.702799 | TASK [bindep : Define bindep_file fact] 2025-12-12 00:21:28.727679 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.736173 | 2025-12-12 00:21:28.736239 | TASK [bindep : Include bindep tasks] 2025-12-12 00:21:28.770810 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.778063 | 2025-12-12 00:21:28.778128 | TASK [bindep : Include install tasks] 2025-12-12 00:21:28.814626 | controller | skipping: Conditional result was False 2025-12-12 00:21:28.830105 | 2025-12-12 00:21:28.830254 | LOOP [bindep : Include package tasks] 2025-12-12 00:21:28.914595 | 2025-12-12 00:21:28.914856 | TASK [Run test-setup role] 2025-12-12 00:21:28.938457 | controller | ok 2025-12-12 00:21:28.965628 | 2025-12-12 00:21:28.965731 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-12 00:21:29.189543 | controller | ok 2025-12-12 00:21:29.199880 | 2025-12-12 00:21:29.199990 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-12 00:21:29.750208 | controller | skipping: Conditional result was False 2025-12-12 00:21:29.798404 | 2025-12-12 00:21:29.798565 | PLAY RECAP 2025-12-12 00:21:29.798654 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-12 00:21:29.798706 | 2025-12-12 00:21:29.960757 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-12 00:21:29.962599 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-12 00:21:30.608581 | 2025-12-12 00:21:30.608704 | PLAY [controller] 2025-12-12 00:21:30.628804 | 2025-12-12 00:21:30.628883 | TASK [Create the /root directory] 2025-12-12 00:21:31.213259 | controller | ok 2025-12-12 00:21:31.225868 | 2025-12-12 00:21:31.226054 | TASK [Install glibc-langpack-en] 2025-12-12 00:21:35.225351 | controller | ok: Nothing to do 2025-12-12 00:21:35.242523 | 2025-12-12 00:21:35.242781 | TASK [Ensure controller directory exists] 2025-12-12 00:21:35.486850 | controller | changed 2025-12-12 00:21:35.500440 | 2025-12-12 00:21:35.500579 | TASK [Install container runtime] 2025-12-12 00:21:35.580215 | controller | ok 2025-12-12 00:21:35.640773 | 2025-12-12 00:21:35.640919 | LOOP [ensure-podman : Find distribution installation] 2025-12-12 00:21:35.689805 | controller | ok: "/var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-12 00:21:35.703748 | controller | included: /var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-12 00:21:35.710224 | 2025-12-12 00:21:35.710295 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-12 00:22:40.745933 | controller | changed 2025-12-12 00:22:40.760284 | 2025-12-12 00:22:40.760423 | TASK [ensure-podman : Fetch podman version] 2025-12-12 00:22:41.328353 | controller | Client: Podman Engine 2025-12-12 00:22:41.356707 | controller | Version: 4.6.2 2025-12-12 00:22:41.356762 | controller | API Version: 4.6.2 2025-12-12 00:22:41.356825 | controller | Go Version: go1.19.12 2025-12-12 00:22:41.356851 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-12 00:22:41.356864 | controller | OS/Arch: linux/amd64 2025-12-12 00:22:41.808673 | controller | ok: Runtime: 0:00:00.212856 2025-12-12 00:22:41.823819 | 2025-12-12 00:22:41.824008 | TASK [ensure-podman : Print podman version installed] 2025-12-12 00:22:41.865402 | Podman version: Client: Podman Engine 2025-12-12 00:22:41.865666 | Version: 4.6.2 2025-12-12 00:22:41.865732 | API Version: 4.6.2 2025-12-12 00:22:41.865777 | Go Version: go1.19.12 2025-12-12 00:22:41.865817 | Built: Mon Aug 28 19:38:31 2023 2025-12-12 00:22:41.865860 | OS/Arch: linux/amd64 2025-12-12 00:22:41.878834 | 2025-12-12 00:22:41.878980 | TASK [ensure-podman : Validate podman engine] 2025-12-12 00:22:42.428257 | controller | skipping: Conditional result was False 2025-12-12 00:22:42.435670 | 2025-12-12 00:22:42.435755 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-12 00:22:42.460518 | controller | skipping: Conditional result was False 2025-12-12 00:22:42.486951 | 2025-12-12 00:22:42.487263 | TASK [Ensure python3.8 is present] 2025-12-12 00:22:42.515356 | controller | skipping: Conditional result was False 2025-12-12 00:22:42.526462 | 2025-12-12 00:22:42.526727 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-12 00:22:42.557420 | controller | ok 2025-12-12 00:22:42.584261 | 2025-12-12 00:22:42.584335 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-12 00:22:44.070097 | controller | ok: Nothing to do 2025-12-12 00:22:44.076711 | 2025-12-12 00:22:44.076789 | TASK [our-ensure-python : Also install python3-devel] 2025-12-12 00:22:53.474318 | controller | changed 2025-12-12 00:22:53.500551 | 2025-12-12 00:22:53.500644 | TASK [Run ensure-virtualenv role] 2025-12-12 00:22:53.523496 | controller | ok 2025-12-12 00:22:53.551856 | 2025-12-12 00:22:53.551932 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-12 00:22:53.827513 | controller | /usr/bin/virtualenv 2025-12-12 00:22:54.130716 | controller | ok: Runtime: 0:00:00.005336 2025-12-12 00:22:54.148704 | 2025-12-12 00:22:54.148850 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-12 00:22:54.187253 | controller | skipping: Conditional result was False 2025-12-12 00:22:54.187755 | controller | ok: All items complete 2025-12-12 00:22:54.187815 | 2025-12-12 00:22:54.216346 | 2025-12-12 00:22:54.216524 | TASK [Find the full path of the Python interpreter] 2025-12-12 00:22:54.444919 | controller | /usr/bin/python3 2025-12-12 00:22:54.770244 | controller | ok 2025-12-12 00:22:54.775942 | 2025-12-12 00:22:54.776054 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-12 00:22:55.699958 | controller | created virtual environment CPython3.11.0.final.0-64 in 482ms 2025-12-12 00:22:55.719784 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-12 00:22:55.719800 | 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-12 00:22:55.719815 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-12 00:22:55.719827 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-12 00:22:55.808082 | controller | changed 2025-12-12 00:22:55.822607 | 2025-12-12 00:22:55.822773 | TASK [Set selinux package] 2025-12-12 00:22:55.862920 | controller | ok 2025-12-12 00:22:55.874492 | 2025-12-12 00:22:55.874633 | TASK [Set selinux package (Fedora)] 2025-12-12 00:22:55.918718 | controller | ok 2025-12-12 00:22:55.924073 | 2025-12-12 00:22:55.924146 | TASK [Install selinux into virtualenv] 2025-12-12 00:23:21.383467 | controller | Collecting selinux-please-lie-to-me 2025-12-12 00:23:33.650375 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-12 00:23:33.964446 | controller | Collecting setuptools<50.0.0 2025-12-12 00:23:33.969439 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-12 00:23:34.016388 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.4 MB/s eta 0:00:00 2025-12-12 00:23:34.101009 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-12 00:23:34.101230 | controller | Attempting uninstall: setuptools 2025-12-12 00:23:34.103714 | controller | Found existing installation: setuptools 62.6.0 2025-12-12 00:23:34.167681 | controller | Uninstalling setuptools-62.6.0: 2025-12-12 00:23:34.175733 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-12 00:23:34.519073 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-12 00:23:46.023099 | controller | 2025-12-12 00:23:46.112758 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-12 00:23:46.112804 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-12 00:23:46.489184 | controller | ok: Runtime: 0:00:49.975077 2025-12-12 00:23:46.498635 | 2025-12-12 00:23:46.498788 | TASK [Install pytest-forked into virtualenv] 2025-12-12 00:23:56.231186 | controller | Collecting pytest-forked 2025-12-12 00:24:08.594127 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-12 00:24:08.639184 | controller | Collecting py 2025-12-12 00:24:08.646889 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-12 00:24:08.671339 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00 2025-12-12 00:24:08.781806 | controller | Collecting pytest>=3.10 2025-12-12 00:24:08.786465 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-12 00:24:08.803011 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.8 MB/s eta 0:00:00 2025-12-12 00:24:08.844404 | controller | Collecting iniconfig>=1.0.1 2025-12-12 00:24:08.849232 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-12 00:24:08.896800 | controller | Collecting packaging>=22 2025-12-12 00:24:08.900128 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-12 00:24:08.908766 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.5 MB/s eta 0:00:00 2025-12-12 00:24:08.941221 | controller | Collecting pluggy<2,>=1.5 2025-12-12 00:24:08.944569 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-12 00:24:08.994736 | controller | Collecting pygments>=2.7.2 2025-12-12 00:24:09.000115 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-12 00:24:09.029399 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 46.2 MB/s eta 0:00:00 2025-12-12 00:24:09.099503 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-12 00:24:10.145120 | 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-12 00:24:10.153996 | controller | 2025-12-12 00:24:10.229940 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-12 00:24:10.230107 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-12 00:24:10.564577 | controller | ok: Runtime: 0:00:23.484237 2025-12-12 00:24:10.583654 | 2025-12-12 00:24:10.583841 | TASK [Update pip] 2025-12-12 00:24:11.105920 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-12 00:24:20.973114 | controller | Collecting pip 2025-12-12 00:24:33.163017 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-12 00:24:33.227188 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.0 MB/s eta 0:00:00 2025-12-12 00:24:33.294049 | controller | Installing collected packages: pip 2025-12-12 00:24:33.294193 | controller | Attempting uninstall: pip 2025-12-12 00:24:33.296413 | controller | Found existing installation: pip 22.2.2 2025-12-12 00:24:33.438373 | controller | Uninstalling pip-22.2.2: 2025-12-12 00:24:33.454796 | controller | Successfully uninstalled pip-22.2.2 2025-12-12 00:24:34.374169 | controller | Successfully installed pip-25.3 2025-12-12 00:24:34.650377 | controller | ok: Runtime: 0:00:23.666347 2025-12-12 00:24:34.662997 | 2025-12-12 00:24:34.663163 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-12 00:24:34.899893 | controller | changed 2025-12-12 00:24:34.913128 | 2025-12-12 00:24:34.913311 | TASK [Install ansible into virtualenv] 2025-12-12 00:24:35.510114 | controller | Processing ./src/github.com/ansible/ansible 2025-12-12 00:24:35.513740 | controller | Installing build dependencies: started 2025-12-12 00:24:58.124371 | controller | Installing build dependencies: finished with status 'done' 2025-12-12 00:24:58.125750 | controller | Getting requirements to build wheel: started 2025-12-12 00:24:58.880389 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-12 00:24:58.881840 | controller | Preparing metadata (pyproject.toml): started 2025-12-12 00:24:59.366942 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-12 00:24:59.373194 | 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-12 00:24:59.376983 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-12 00:24:59.503721 | controller | ERROR 2025-12-12 00:24:59.503958 | controller | { 2025-12-12 00:24:59.504052 | controller | "delta": "0:00:24.268510", 2025-12-12 00:24:59.504104 | controller | "end": "2025-12-12 00:24:59.453202", 2025-12-12 00:24:59.504144 | controller | "msg": "non-zero return code", 2025-12-12 00:24:59.504196 | controller | "rc": 1, 2025-12-12 00:24:59.504233 | controller | "start": "2025-12-12 00:24:35.184692" 2025-12-12 00:24:59.504268 | controller | } failure 2025-12-12 00:24:59.507224 | 2025-12-12 00:24:59.507325 | PLAY RECAP 2025-12-12 00:24:59.507415 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-12 00:24:59.507459 | 2025-12-12 00:24:59.653269 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-12 00:24:59.654228 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-12 00:25:00.236905 | 2025-12-12 00:25:00.237047 | PLAY [all] 2025-12-12 00:25:00.258353 | 2025-12-12 00:25:00.258455 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-12 00:25:00.736616 | controller | changed: non-zero return code 2025-12-12 00:25:00.751441 | 2025-12-12 00:25:00.751670 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-12 00:25:00.779284 | controller | skipping: Conditional result was False 2025-12-12 00:25:00.793328 | 2025-12-12 00:25:00.793492 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-12 00:25:00.835227 | 2025-12-12 00:25:00.835508 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-12 00:25:00.875808 | 2025-12-12 00:25:00.876117 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-12 00:25:00.902328 | controller | skipping: Conditional result was False 2025-12-12 00:25:00.918473 | 2025-12-12 00:25:00.918628 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-12 00:25:00.958919 | 2025-12-12 00:25:00.959240 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-12 00:25:00.986293 | controller | skipping: Conditional result was False 2025-12-12 00:25:00.999638 | 2025-12-12 00:25:00.999787 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-12 00:25:01.026056 | controller | skipping: Conditional result was False 2025-12-12 00:25:01.039569 | 2025-12-12 00:25:01.039726 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-12 00:25:01.066111 | controller | skipping: Conditional result was False 2025-12-12 00:25:01.109867 | 2025-12-12 00:25:01.109958 | PLAY RECAP 2025-12-12 00:25:01.110005 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-12 00:25:01.110048 | 2025-12-12 00:25:01.229815 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-12 00:25:01.231891 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-12 00:25:01.779832 | 2025-12-12 00:25:01.779941 | PLAY [all:!appliance*] 2025-12-12 00:25:01.801232 | 2025-12-12 00:25:01.801344 | TASK [unregister the node] 2025-12-12 00:25:02.334906 | controller | skipping: Conditional result was False 2025-12-12 00:25:02.342172 | 2025-12-12 00:25:02.342271 | TASK [include_role : fetch-output] 2025-12-12 00:25:02.374364 | controller | ok 2025-12-12 00:25:02.396660 | 2025-12-12 00:25:02.396796 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-12 00:25:02.452595 | controller | skipping: Conditional result was False 2025-12-12 00:25:02.460044 | 2025-12-12 00:25:02.460134 | TASK [fetch-output : Set log path for single node] 2025-12-12 00:25:02.502065 | controller | ok 2025-12-12 00:25:02.508395 | 2025-12-12 00:25:02.508553 | LOOP [fetch-output : Ensure local output dirs] 2025-12-12 00:25:03.059605 | controller -> localhost | ok: "/var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/logs" 2025-12-12 00:25:03.350353 | controller -> localhost | changed: "/var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/artifacts" 2025-12-12 00:25:03.568842 | controller -> localhost | changed: "/var/lib/zuul/builds/7ec0e3e9cacb4c558fc7e7a3127d0846/work/docs" 2025-12-12 00:25:03.594358 | 2025-12-12 00:25:03.594953 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-12 00:25:04.230136 | controller | changed: 2025-12-12 00:25:04.230498 | controller | .d..t...... ./ 2025-12-12 00:25:04.230531 | controller | cd+++++++++ controller/ 2025-12-12 00:25:04.230606 | controller | changed: All items complete 2025-12-12 00:25:04.230633 | 2025-12-12 00:25:04.733822 | controller | changed: .d..t...... ./ 2025-12-12 00:25:05.301131 | controller | changed: .d..t...... ./ 2025-12-12 00:25:05.337473 | 2025-12-12 00:25:05.337693 | TASK [include_role : fetch-output-openshift] 2025-12-12 00:25:05.358308 | controller | skipping: Conditional result was False 2025-12-12 00:25:05.376436 | 2025-12-12 00:25:05.376674 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-12 00:25:05.429895 | controller | skipping: Conditional result was False 2025-12-12 00:25:05.443317 | controller | skipping: Conditional result was False 2025-12-12 00:25:05.500078 | 2025-12-12 00:25:05.500253 | PLAY [localhost] 2025-12-12 00:25:05.514932 | 2025-12-12 00:25:05.515122 | TASK [Run Zuul manifest role] 2025-12-12 00:25:05.539905 | localhost | ok 2025-12-12 00:25:05.579866 | 2025-12-12 00:25:05.580063 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-12 00:25:06.014402 | localhost | changed 2025-12-12 00:25:06.026851 | 2025-12-12 00:25:06.027159 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-12 00:25:06.066947 | localhost | ok 2025-12-12 00:25:06.084330 | 2025-12-12 00:25:06.084544 | TASK [Set zuul-log-path fact] 2025-12-12 00:25:06.116435 | localhost | ok 2025-12-12 00:25:06.167058 | 2025-12-12 00:25:06.167747 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-12 00:25:06.217050 | localhost | ok 2025-12-12 00:25:06.233170 | 2025-12-12 00:25:06.233354 | LOOP [Run upload-logs-swift role] 2025-12-12 00:25:06.292187 | localhost | Output suppressed because no_log was given 2025-12-12 00:25:06.332060 | 2025-12-12 00:25:06.332237 | TASK [Set zuul-log-path fact] 2025-12-12 00:25:06.369324 | localhost | skipping: Conditional result was False 2025-12-12 00:25:06.376586 | 2025-12-12 00:25:06.376660 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-12 00:25:06.869649 | localhost -> localhost | ok: Runtime: 0:00:00.015024 2025-12-12 00:25:06.966907 | 2025-12-12 00:25:06.967156 | TASK [upload-logs-swift : Upload logs to swift]