2025-12-04 00:22:12.799696 | Job console starting... 2025-12-04 00:22:12.815859 | Updating repositories 2025-12-04 00:22:12.953186 | Preparing job workspace 2025-12-04 00:22:17.013266 | Running Ansible setup... 2025-12-04 00:22:21.749781 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-04 00:22:22.339357 | 2025-12-04 00:22:22.339497 | PLAY [localhost] 2025-12-04 00:22:22.348650 | 2025-12-04 00:22:22.348787 | TASK [Gathering Facts] 2025-12-04 00:22:23.413399 | localhost | ok 2025-12-04 00:22:23.427362 | 2025-12-04 00:22:23.427505 | TASK [Setup log path fact] 2025-12-04 00:22:23.445728 | localhost | ok 2025-12-04 00:22:23.460143 | 2025-12-04 00:22:23.460231 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-04 00:22:23.487993 | localhost | ok 2025-12-04 00:22:23.499166 | 2025-12-04 00:22:23.499557 | TASK [emit-job-header : Print job information] 2025-12-04 00:22:23.544955 | # Job Information 2025-12-04 00:22:23.545169 | Ansible Version: 2.15.12 2025-12-04 00:22:23.545212 | Job: ansible-test-sanity-docker-milestone 2025-12-04 00:22:23.545241 | Pipeline: periodic 2025-12-04 00:22:23.545266 | Executor: ze02.softwarefactory-project.io 2025-12-04 00:22:23.545290 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-04 00:22:23.545319 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/4f1/ansible/4f127fa4d7054b5c974dbb8eb1a237cc/ 2025-12-04 00:22:23.545346 | Event ID: 21f6f916db01404d9ca1e0a410197a8e 2025-12-04 00:22:23.550629 | 2025-12-04 00:22:23.550734 | LOOP [emit-job-header : Print node information] 2025-12-04 00:22:23.661804 | localhost | ok: 2025-12-04 00:22:23.662083 | localhost | # Node Information 2025-12-04 00:22:23.662138 | localhost | Inventory Hostname: controller 2025-12-04 00:22:23.662181 | localhost | Hostname: np0005544915 2025-12-04 00:22:23.662222 | localhost | Username: zuul 2025-12-04 00:22:23.662288 | localhost | Distro: Fedora 37 2025-12-04 00:22:23.662329 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-04 00:22:23.662366 | localhost | Region: ca-ymq-1 2025-12-04 00:22:23.662402 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-04 00:22:23.662438 | localhost | Product Name: OpenStack Nova 2025-12-04 00:22:23.662474 | localhost | Interface IP: 162.253.55.42 2025-12-04 00:22:23.679540 | 2025-12-04 00:22:23.679706 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-04 00:22:24.138735 | localhost -> localhost | changed 2025-12-04 00:22:24.145080 | 2025-12-04 00:22:24.145147 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-04 00:22:25.125642 | localhost -> localhost | changed 2025-12-04 00:22:25.147405 | 2025-12-04 00:22:25.147482 | PLAY [all:!appliance*] 2025-12-04 00:22:25.163920 | 2025-12-04 00:22:25.164001 | TASK [include_role : start-zuul-console] 2025-12-04 00:22:25.186472 | controller | ok 2025-12-04 00:22:25.201167 | 2025-12-04 00:22:25.201284 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-04 00:22:25.597740 | controller | ok 2025-12-04 00:22:25.609685 | 2025-12-04 00:22:25.609760 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-04 00:22:26.584206 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-04 00:22:26.600860 | 2025-12-04 00:22:26.601029 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-04 00:22:27.151137 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.168935 | 2025-12-04 00:22:27.169154 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-04 00:22:27.199771 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.216046 | 2025-12-04 00:22:27.216239 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-04 00:22:27.245929 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.262181 | 2025-12-04 00:22:27.262394 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-04 00:22:27.290922 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.300489 | 2025-12-04 00:22:27.300586 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-04 00:22:27.327346 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.336897 | 2025-12-04 00:22:27.336991 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-04 00:22:27.363826 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.383032 | 2025-12-04 00:22:27.383126 | TASK [Disable Fedora Modular] 2025-12-04 00:22:27.649029 | controller | changed 2025-12-04 00:22:27.664286 | 2025-12-04 00:22:27.664429 | TASK [Enable EPEL] 2025-12-04 00:22:27.695174 | controller | skipping: Conditional result was False 2025-12-04 00:22:27.705777 | 2025-12-04 00:22:27.705890 | TASK [Register the RHEL node] 2025-12-04 00:22:28.272657 | 2025-12-04 00:22:28.273095 | TASK [Show the subscription-manager status] 2025-12-04 00:22:28.874153 | controller | skipping: Conditional result was False 2025-12-04 00:22:28.886566 | 2025-12-04 00:22:28.886673 | TASK [Enable EPEL on RHEL] 2025-12-04 00:22:29.434799 | controller | skipping: Conditional result was False 2025-12-04 00:22:29.449391 | 2025-12-04 00:22:29.449593 | TASK [Install git and tox] 2025-12-04 00:23:58.932756 | controller | changed 2025-12-04 00:23:58.947412 | 2025-12-04 00:23:58.947580 | TASK [include_role : prepare-workspace] 2025-12-04 00:23:58.988650 | controller | ok 2025-12-04 00:23:59.024479 | 2025-12-04 00:23:59.024586 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-04 00:23:59.278341 | controller | ok 2025-12-04 00:23:59.295045 | 2025-12-04 00:23:59.295181 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-04 00:24:11.263686 | controller | Output suppressed because no_log was given 2025-12-04 00:24:11.277275 | 2025-12-04 00:24:11.277353 | TASK [include_role : prepare-workspace-openshift] 2025-12-04 00:24:11.302700 | controller | skipping: Conditional result was False 2025-12-04 00:24:11.363429 | 2025-12-04 00:24:11.363556 | PLAY [all:!appliance] 2025-12-04 00:24:11.378355 | 2025-12-04 00:24:11.378414 | TASK [Run add-build-sshkey role (RSA)] 2025-12-04 00:24:11.410502 | controller | ok 2025-12-04 00:24:11.426401 | 2025-12-04 00:24:11.426476 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-04 00:24:11.717787 | controller -> localhost | ok 2025-12-04 00:24:11.724702 | 2025-12-04 00:24:11.724789 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-04 00:24:11.744751 | controller | ok 2025-12-04 00:24:11.758797 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-04 00:24:11.765597 | 2025-12-04 00:24:11.765680 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-04 00:24:12.291502 | controller -> localhost | Generating public/private rsa key pair. 2025-12-04 00:24:12.292432 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_rsa. 2025-12-04 00:24:12.292482 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_rsa.pub. 2025-12-04 00:24:12.292512 | controller -> localhost | The key fingerprint is: 2025-12-04 00:24:12.292539 | controller -> localhost | SHA256:FYRB4OHs2F3nTrMPh/s/zXno9EZvvBVwnujTKgOz8Ww zuul-build-sshkey 2025-12-04 00:24:12.292566 | controller -> localhost | The key's randomart image is: 2025-12-04 00:24:12.292592 | controller -> localhost | +---[RSA 2048]----+ 2025-12-04 00:24:12.292617 | controller -> localhost | | ooo+o | 2025-12-04 00:24:12.292644 | controller -> localhost | | + .. . | 2025-12-04 00:24:12.292697 | controller -> localhost | | + o .. . | 2025-12-04 00:24:12.292729 | controller -> localhost | | + . o o = .| 2025-12-04 00:24:12.292754 | controller -> localhost | | . o S +. + | 2025-12-04 00:24:12.292790 | controller -> localhost | | + o.+. o| 2025-12-04 00:24:12.292821 | controller -> localhost | | B =oo*=| 2025-12-04 00:24:12.292851 | controller -> localhost | | . E *++X| 2025-12-04 00:24:12.292877 | controller -> localhost | | . +++=*| 2025-12-04 00:24:12.292905 | controller -> localhost | +----[SHA256]-----+ 2025-12-04 00:24:12.292973 | controller -> localhost | ok: Runtime: 0:00:00.095815 2025-12-04 00:24:12.306913 | 2025-12-04 00:24:12.307010 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-04 00:24:12.362119 | controller | ok 2025-12-04 00:24:12.372886 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-04 00:24:12.381806 | 2025-12-04 00:24:12.381873 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-04 00:24:12.406719 | controller | skipping: Conditional result was False 2025-12-04 00:24:12.414330 | 2025-12-04 00:24:12.414398 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-04 00:24:12.872462 | controller | changed 2025-12-04 00:24:12.882840 | 2025-12-04 00:24:12.882971 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-04 00:24:13.101526 | controller | ok 2025-12-04 00:24:13.112278 | 2025-12-04 00:24:13.112450 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-04 00:24:13.730722 | controller | changed 2025-12-04 00:24:13.737593 | 2025-12-04 00:24:13.737656 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-04 00:24:14.358096 | controller | changed 2025-12-04 00:24:14.374897 | 2025-12-04 00:24:14.375179 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-04 00:24:14.403061 | controller | skipping: Conditional result was False 2025-12-04 00:24:14.421420 | 2025-12-04 00:24:14.421586 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-04 00:24:14.831358 | controller -> localhost | changed 2025-12-04 00:24:14.850763 | 2025-12-04 00:24:14.850874 | TASK [add-build-sshkey : Add back temp key] 2025-12-04 00:24:15.118436 | controller -> localhost | Identity added: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_rsa (zuul-build-sshkey) 2025-12-04 00:24:15.118984 | controller -> localhost | ok: Runtime: 0:00:00.007755 2025-12-04 00:24:15.134847 | 2025-12-04 00:24:15.135016 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-04 00:29:17.005573 | controller | ok 2025-12-04 00:29:17.014743 | 2025-12-04 00:29:17.014915 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-04 00:29:17.053046 | controller | skipping: Conditional result was False 2025-12-04 00:29:17.087083 | 2025-12-04 00:29:17.087258 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-04 00:29:17.111173 | controller | ok 2025-12-04 00:29:17.164452 | 2025-12-04 00:29:17.164587 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-04 00:29:17.391249 | controller -> localhost | ok 2025-12-04 00:29:17.397754 | 2025-12-04 00:29:17.397818 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-04 00:29:17.426963 | controller | ok 2025-12-04 00:29:17.438019 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-04 00:29:17.443740 | 2025-12-04 00:29:17.443802 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-04 00:29:17.770242 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-04 00:29:17.770572 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_ecdsa. 2025-12-04 00:29:17.770615 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_ecdsa.pub. 2025-12-04 00:29:17.770659 | controller -> localhost | The key fingerprint is: 2025-12-04 00:29:17.770718 | controller -> localhost | SHA256:Shyl6vBv8378SloORqOD9cKLk2wwtU5YZGt3mJL68pU zuul-build-sshkey 2025-12-04 00:29:17.770746 | controller -> localhost | The key's randomart image is: 2025-12-04 00:29:17.770772 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-04 00:29:17.770796 | controller -> localhost | | . | 2025-12-04 00:29:17.770820 | controller -> localhost | | o o | 2025-12-04 00:29:17.770844 | controller -> localhost | | o ooo | 2025-12-04 00:29:17.770867 | controller -> localhost | | Bo+.. | 2025-12-04 00:29:17.770891 | controller -> localhost | | .*.++.S | 2025-12-04 00:29:17.770914 | controller -> localhost | | =+o= * . | 2025-12-04 00:29:17.770937 | controller -> localhost | | B+.E +.o | 2025-12-04 00:29:17.770961 | controller -> localhost | | . B+o= *o | 2025-12-04 00:29:17.770984 | controller -> localhost | | +ooo++.oo. | 2025-12-04 00:29:17.771007 | controller -> localhost | +----[SHA256]-----+ 2025-12-04 00:29:17.771079 | controller -> localhost | ok: Runtime: 0:00:00.007365 2025-12-04 00:29:17.782161 | 2025-12-04 00:29:17.782256 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-04 00:29:17.806153 | controller | ok 2025-12-04 00:29:17.816812 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-04 00:29:17.829774 | 2025-12-04 00:29:17.829859 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-04 00:29:17.855037 | controller | skipping: Conditional result was False 2025-12-04 00:29:17.861872 | 2025-12-04 00:29:17.861937 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-04 00:29:18.144303 | controller | changed 2025-12-04 00:29:18.157361 | 2025-12-04 00:29:18.157524 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-04 00:29:18.390051 | controller | ok 2025-12-04 00:29:18.403754 | 2025-12-04 00:29:18.403900 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-04 00:29:19.057166 | controller | changed 2025-12-04 00:29:19.073772 | 2025-12-04 00:29:19.074013 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-04 00:29:19.736632 | controller | changed 2025-12-04 00:29:19.749976 | 2025-12-04 00:29:19.750115 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-04 00:29:19.778118 | controller | skipping: Conditional result was False 2025-12-04 00:29:19.793055 | 2025-12-04 00:29:19.793196 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-04 00:29:20.075903 | controller -> localhost | changed 2025-12-04 00:29:20.093155 | 2025-12-04 00:29:20.093381 | TASK [add-build-sshkey : Add back temp key] 2025-12-04 00:29:20.476192 | controller -> localhost | Identity added: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/4f127fa4d7054b5c974dbb8eb1a237cc_id_ecdsa (zuul-build-sshkey) 2025-12-04 00:29:20.476447 | controller -> localhost | ok: Runtime: 0:00:00.008325 2025-12-04 00:29:20.483651 | 2025-12-04 00:29:20.483742 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-04 00:29:20.690994 | controller | ok 2025-12-04 00:29:20.707100 | 2025-12-04 00:29:20.707314 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-04 00:29:20.752359 | controller | skipping: Conditional result was False 2025-12-04 00:29:20.766856 | 2025-12-04 00:29:20.766952 | TASK [include_role : remove-zuul-sshkey] 2025-12-04 00:29:20.793536 | controller | skipping: Conditional result was False 2025-12-04 00:29:20.801837 | 2025-12-04 00:29:20.801913 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-04 00:29:21.074919 | controller | ok: "logs" 2025-12-04 00:29:21.075498 | controller | ok: All items complete 2025-12-04 00:29:21.075566 | 2025-12-04 00:29:21.272649 | controller | ok: "artifacts" 2025-12-04 00:29:21.468759 | controller | ok: "docs" 2025-12-04 00:29:21.494129 | 2025-12-04 00:29:21.494396 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-04 00:29:21.739087 | controller | changed: "logs" 2025-12-04 00:29:21.942084 | controller | changed: "artifacts" 2025-12-04 00:29:22.150718 | controller | changed: "docs" 2025-12-04 00:29:22.217377 | 2025-12-04 00:29:22.217522 | PLAY RECAP 2025-12-04 00:29:22.217580 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-04 00:29:22.217616 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-04 00:29:22.217640 | 2025-12-04 00:29:22.374145 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-04 00:29:22.375389 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-04 00:29:22.953979 | 2025-12-04 00:29:22.954095 | PLAY [all] 2025-12-04 00:29:22.977621 | 2025-12-04 00:29:22.977796 | TASK [Install binary dependencies] 2025-12-04 00:29:23.065555 | controller | ok 2025-12-04 00:29:23.098308 | 2025-12-04 00:29:23.098446 | TASK [bindep : Include find tasks] 2025-12-04 00:29:23.131351 | controller | ok 2025-12-04 00:29:23.142133 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-04 00:29:23.150769 | 2025-12-04 00:29:23.150859 | TASK [bindep : Look for bindep.txt] 2025-12-04 00:29:23.709917 | controller | ok 2025-12-04 00:29:23.723106 | 2025-12-04 00:29:23.723251 | TASK [bindep : Define bindep_file fact] 2025-12-04 00:29:23.751251 | controller | skipping: Conditional result was False 2025-12-04 00:29:23.765271 | 2025-12-04 00:29:23.765418 | TASK [bindep : Look for other-requirements.txt] 2025-12-04 00:29:23.998895 | controller | ok 2025-12-04 00:29:24.012369 | 2025-12-04 00:29:24.012523 | TASK [bindep : Define bindep_file fact] 2025-12-04 00:29:24.050782 | controller | skipping: Conditional result was False 2025-12-04 00:29:24.058032 | 2025-12-04 00:29:24.058111 | TASK [bindep : Look for bindep fallback file] 2025-12-04 00:29:24.103247 | controller | skipping: Conditional result was False 2025-12-04 00:29:24.110773 | 2025-12-04 00:29:24.110850 | TASK [bindep : Define bindep_file fact] 2025-12-04 00:29:24.145488 | controller | skipping: Conditional result was False 2025-12-04 00:29:24.152039 | 2025-12-04 00:29:24.152111 | TASK [bindep : Include bindep tasks] 2025-12-04 00:29:24.187455 | controller | skipping: Conditional result was False 2025-12-04 00:29:24.203325 | 2025-12-04 00:29:24.203620 | TASK [bindep : Include install tasks] 2025-12-04 00:29:24.241789 | controller | skipping: Conditional result was False 2025-12-04 00:29:24.258486 | 2025-12-04 00:29:24.258648 | LOOP [bindep : Include package tasks] 2025-12-04 00:29:24.344215 | 2025-12-04 00:29:24.344503 | TASK [Run test-setup role] 2025-12-04 00:29:24.387397 | controller | ok 2025-12-04 00:29:24.416805 | 2025-12-04 00:29:24.416902 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-04 00:29:24.630072 | controller | ok 2025-12-04 00:29:24.652246 | 2025-12-04 00:29:24.652709 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-04 00:29:25.208616 | controller | skipping: Conditional result was False 2025-12-04 00:29:25.265110 | 2025-12-04 00:29:25.265260 | PLAY RECAP 2025-12-04 00:29:25.265323 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-04 00:29:25.265353 | 2025-12-04 00:29:25.418007 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-04 00:29:25.419220 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-04 00:29:26.068405 | 2025-12-04 00:29:26.068570 | PLAY [controller] 2025-12-04 00:29:26.089587 | 2025-12-04 00:29:26.089703 | TASK [Create the /root directory] 2025-12-04 00:29:26.671019 | controller | ok 2025-12-04 00:29:26.677617 | 2025-12-04 00:29:26.677721 | TASK [Install glibc-langpack-en] 2025-12-04 00:29:30.587015 | controller | ok: Nothing to do 2025-12-04 00:29:30.599288 | 2025-12-04 00:29:30.599418 | TASK [Ensure controller directory exists] 2025-12-04 00:29:30.824442 | controller | changed 2025-12-04 00:29:30.838274 | 2025-12-04 00:29:30.838417 | TASK [Install container runtime] 2025-12-04 00:29:30.920999 | controller | ok 2025-12-04 00:29:30.983890 | 2025-12-04 00:29:30.984073 | LOOP [ensure-podman : Find distribution installation] 2025-12-04 00:29:31.026734 | controller | ok: "/var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-04 00:29:31.039292 | controller | included: /var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-04 00:29:31.048318 | 2025-12-04 00:29:31.048407 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-04 00:30:35.847157 | controller | changed 2025-12-04 00:30:35.863646 | 2025-12-04 00:30:35.863906 | TASK [ensure-podman : Fetch podman version] 2025-12-04 00:30:36.449463 | controller | Client: Podman Engine 2025-12-04 00:30:36.480294 | controller | Version: 4.6.2 2025-12-04 00:30:36.480354 | controller | API Version: 4.6.2 2025-12-04 00:30:36.480368 | controller | Go Version: go1.19.12 2025-12-04 00:30:36.480399 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-04 00:30:36.480424 | controller | OS/Arch: linux/amd64 2025-12-04 00:30:36.920541 | controller | ok: Runtime: 0:00:00.201883 2025-12-04 00:30:36.930343 | 2025-12-04 00:30:36.930431 | TASK [ensure-podman : Print podman version installed] 2025-12-04 00:30:36.975768 | Podman version: Client: Podman Engine 2025-12-04 00:30:36.976018 | Version: 4.6.2 2025-12-04 00:30:36.976057 | API Version: 4.6.2 2025-12-04 00:30:36.976085 | Go Version: go1.19.12 2025-12-04 00:30:36.976111 | Built: Mon Aug 28 19:38:31 2023 2025-12-04 00:30:36.976137 | OS/Arch: linux/amd64 2025-12-04 00:30:36.984126 | 2025-12-04 00:30:36.984205 | TASK [ensure-podman : Validate podman engine] 2025-12-04 00:30:37.527879 | controller | skipping: Conditional result was False 2025-12-04 00:30:37.542289 | 2025-12-04 00:30:37.542430 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-04 00:30:37.570080 | controller | skipping: Conditional result was False 2025-12-04 00:30:37.595228 | 2025-12-04 00:30:37.595413 | TASK [Ensure python3.8 is present] 2025-12-04 00:30:37.623050 | controller | skipping: Conditional result was False 2025-12-04 00:30:37.635828 | 2025-12-04 00:30:37.635961 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-04 00:30:37.672182 | controller | ok 2025-12-04 00:30:37.700186 | 2025-12-04 00:30:37.700332 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-04 00:30:39.408808 | controller | ok: Nothing to do 2025-12-04 00:30:39.421398 | 2025-12-04 00:30:39.421563 | TASK [our-ensure-python : Also install python3-devel] 2025-12-04 00:30:47.971621 | controller | changed 2025-12-04 00:30:47.999533 | 2025-12-04 00:30:47.999657 | TASK [Run ensure-virtualenv role] 2025-12-04 00:30:48.024924 | controller | ok 2025-12-04 00:30:48.054812 | 2025-12-04 00:30:48.054920 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-04 00:30:48.326849 | controller | /usr/bin/virtualenv 2025-12-04 00:30:48.594254 | controller | ok: Runtime: 0:00:00.005474 2025-12-04 00:30:48.610521 | 2025-12-04 00:30:48.610821 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-04 00:30:48.639572 | controller | skipping: Conditional result was False 2025-12-04 00:30:48.640336 | controller | ok: All items complete 2025-12-04 00:30:48.641523 | 2025-12-04 00:30:48.681086 | 2025-12-04 00:30:48.681373 | TASK [Find the full path of the Python interpreter] 2025-12-04 00:30:49.017205 | controller | /usr/bin/python3 2025-12-04 00:30:49.303063 | controller | ok 2025-12-04 00:30:49.316798 | 2025-12-04 00:30:49.317473 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-04 00:30:50.160915 | controller | created virtual environment CPython3.11.0.final.0-64 in 466ms 2025-12-04 00:30:50.193640 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-04 00:30:50.194004 | 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-04 00:30:50.194101 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-04 00:30:50.194297 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-04 00:30:50.385324 | controller | changed 2025-12-04 00:30:50.398780 | 2025-12-04 00:30:50.398949 | TASK [Set selinux package] 2025-12-04 00:30:50.456538 | controller | ok 2025-12-04 00:30:50.468324 | 2025-12-04 00:30:50.468485 | TASK [Set selinux package (Fedora)] 2025-12-04 00:30:50.503312 | controller | ok 2025-12-04 00:30:50.511200 | 2025-12-04 00:30:50.511292 | TASK [Install selinux into virtualenv] 2025-12-04 00:30:51.853242 | controller | Collecting selinux-please-lie-to-me 2025-12-04 00:30:51.894301 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-04 00:30:52.208764 | controller | Collecting setuptools<50.0.0 2025-12-04 00:30:52.218713 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-04 00:30:52.259996 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.4 MB/s eta 0:00:00 2025-12-04 00:30:52.343147 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-04 00:30:52.343402 | controller | Attempting uninstall: setuptools 2025-12-04 00:30:52.345844 | controller | Found existing installation: setuptools 62.6.0 2025-12-04 00:30:52.408141 | controller | Uninstalling setuptools-62.6.0: 2025-12-04 00:30:52.417212 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-04 00:30:52.826252 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-04 00:30:52.943416 | controller | 2025-12-04 00:30:53.076235 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-04 00:30:53.076307 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-04 00:30:53.582082 | controller | ok: Runtime: 0:00:02.323354 2025-12-04 00:30:53.596626 | 2025-12-04 00:30:53.596861 | TASK [Install pytest-forked into virtualenv] 2025-12-04 00:30:54.198219 | controller | Collecting pytest-forked 2025-12-04 00:30:54.236129 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-04 00:30:54.276515 | controller | Collecting py 2025-12-04 00:30:54.280676 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-04 00:30:54.298196 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.2 MB/s eta 0:00:00 2025-12-04 00:30:54.402339 | controller | Collecting pytest>=3.10 2025-12-04 00:30:54.409285 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-12-04 00:30:54.425438 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 30.7 MB/s eta 0:00:00 2025-12-04 00:30:54.465959 | controller | Collecting iniconfig>=1.0.1 2025-12-04 00:30:54.470291 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-04 00:30:54.513460 | controller | Collecting packaging>=22 2025-12-04 00:30:54.517231 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-04 00:30:54.524482 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.6 MB/s eta 0:00:00 2025-12-04 00:30:54.556180 | controller | Collecting pluggy<2,>=1.5 2025-12-04 00:30:54.559380 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-04 00:30:54.622837 | controller | Collecting pygments>=2.7.2 2025-12-04 00:30:54.627295 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-04 00:30:54.648205 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 65.7 MB/s eta 0:00:00 2025-12-04 00:30:54.719699 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-04 00:30:55.779632 | 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.1 pytest-forked-1.6.0 2025-12-04 00:30:55.789367 | controller | 2025-12-04 00:30:55.871649 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-04 00:30:55.871662 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-04 00:30:56.158005 | controller | ok: Runtime: 0:00:02.045793 2025-12-04 00:30:56.177205 | 2025-12-04 00:30:56.177396 | TASK [Update pip] 2025-12-04 00:30:56.742235 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-04 00:30:56.867993 | controller | Collecting pip 2025-12-04 00:30:56.901264 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-04 00:30:56.950272 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.4 MB/s eta 0:00:00 2025-12-04 00:30:57.019119 | controller | Installing collected packages: pip 2025-12-04 00:30:57.019343 | controller | Attempting uninstall: pip 2025-12-04 00:30:57.021459 | controller | Found existing installation: pip 22.2.2 2025-12-04 00:30:57.158512 | controller | Uninstalling pip-22.2.2: 2025-12-04 00:30:57.173606 | controller | Successfully uninstalled pip-22.2.2 2025-12-04 00:30:58.013488 | controller | Successfully installed pip-25.3 2025-12-04 00:30:58.281258 | controller | ok: Runtime: 0:00:01.651129 2025-12-04 00:30:58.290892 | 2025-12-04 00:30:58.290981 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-04 00:30:58.515156 | controller | changed 2025-12-04 00:30:58.530041 | 2025-12-04 00:30:58.530253 | TASK [Install ansible into virtualenv] 2025-12-04 00:30:59.042884 | controller | Processing ./src/github.com/ansible/ansible 2025-12-04 00:30:59.046265 | controller | Installing build dependencies: started 2025-12-04 00:31:00.032844 | controller | Installing build dependencies: finished with status 'done' 2025-12-04 00:31:00.776327 | controller | Getting requirements to build wheel: started 2025-12-04 00:31:00.776375 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-04 00:31:01.230843 | controller | Preparing metadata (pyproject.toml): started 2025-12-04 00:31:01.230893 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-04 00:31:01.231530 | 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-04 00:31:01.234126 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-04 00:31:01.590324 | controller | ERROR 2025-12-04 00:31:01.590742 | controller | { 2025-12-04 00:31:01.590800 | controller | "delta": "0:00:02.537371", 2025-12-04 00:31:01.590834 | controller | "end": "2025-12-04 00:31:01.296829", 2025-12-04 00:31:01.590864 | controller | "msg": "non-zero return code", 2025-12-04 00:31:01.590908 | controller | "rc": 1, 2025-12-04 00:31:01.590935 | controller | "start": "2025-12-04 00:30:58.759458" 2025-12-04 00:31:01.590961 | controller | } failure 2025-12-04 00:31:01.593631 | 2025-12-04 00:31:01.593717 | PLAY RECAP 2025-12-04 00:31:01.593776 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-04 00:31:01.593821 | 2025-12-04 00:31:01.783495 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-04 00:31:01.784501 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-04 00:31:02.480077 | 2025-12-04 00:31:02.480246 | PLAY [all] 2025-12-04 00:31:02.503400 | 2025-12-04 00:31:02.503573 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-04 00:31:02.944943 | controller | changed: non-zero return code 2025-12-04 00:31:02.959880 | 2025-12-04 00:31:02.960093 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-04 00:31:02.988616 | controller | skipping: Conditional result was False 2025-12-04 00:31:03.004882 | 2025-12-04 00:31:03.005122 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-04 00:31:03.042629 | 2025-12-04 00:31:03.042889 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-04 00:31:03.080911 | 2025-12-04 00:31:03.081155 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-04 00:31:03.107021 | controller | skipping: Conditional result was False 2025-12-04 00:31:03.118461 | 2025-12-04 00:31:03.118592 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-04 00:31:03.154156 | 2025-12-04 00:31:03.154404 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-04 00:31:03.181506 | controller | skipping: Conditional result was False 2025-12-04 00:31:03.191434 | 2025-12-04 00:31:03.191571 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-04 00:31:03.226823 | controller | skipping: Conditional result was False 2025-12-04 00:31:03.242014 | 2025-12-04 00:31:03.242180 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-04 00:31:03.270335 | controller | skipping: Conditional result was False 2025-12-04 00:31:03.314690 | 2025-12-04 00:31:03.314884 | PLAY RECAP 2025-12-04 00:31:03.314948 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-04 00:31:03.314975 | 2025-12-04 00:31:03.444426 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-04 00:31:03.445791 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-04 00:31:04.083829 | 2025-12-04 00:31:04.083989 | PLAY [all:!appliance*] 2025-12-04 00:31:04.105797 | 2025-12-04 00:31:04.105881 | TASK [unregister the node] 2025-12-04 00:31:04.641531 | controller | skipping: Conditional result was False 2025-12-04 00:31:04.655504 | 2025-12-04 00:31:04.655709 | TASK [include_role : fetch-output] 2025-12-04 00:31:04.710624 | controller | ok 2025-12-04 00:31:04.749590 | 2025-12-04 00:31:04.749719 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-04 00:31:04.826957 | controller | skipping: Conditional result was False 2025-12-04 00:31:04.841517 | 2025-12-04 00:31:04.841726 | TASK [fetch-output : Set log path for single node] 2025-12-04 00:31:04.893524 | controller | ok 2025-12-04 00:31:04.905613 | 2025-12-04 00:31:04.905785 | LOOP [fetch-output : Ensure local output dirs] 2025-12-04 00:31:05.361966 | controller -> localhost | ok: "/var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/logs" 2025-12-04 00:31:05.630301 | controller -> localhost | changed: "/var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/artifacts" 2025-12-04 00:31:05.914447 | controller -> localhost | changed: "/var/lib/zuul/builds/4f127fa4d7054b5c974dbb8eb1a237cc/work/docs" 2025-12-04 00:31:05.928262 | 2025-12-04 00:31:05.928397 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-04 00:31:06.652048 | controller | changed: 2025-12-04 00:31:06.652270 | controller | .d..t...... ./ 2025-12-04 00:31:06.652311 | controller | cd+++++++++ controller/ 2025-12-04 00:31:06.652368 | controller | changed: All items complete 2025-12-04 00:31:06.652395 | 2025-12-04 00:31:07.192846 | controller | changed: .d..t...... ./ 2025-12-04 00:31:07.683820 | controller | changed: .d..t...... ./ 2025-12-04 00:31:07.713882 | 2025-12-04 00:31:07.714232 | TASK [include_role : fetch-output-openshift] 2025-12-04 00:31:07.730482 | controller | skipping: Conditional result was False 2025-12-04 00:31:07.740948 | 2025-12-04 00:31:07.741050 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-04 00:31:07.770302 | controller | skipping: Conditional result was False 2025-12-04 00:31:07.781371 | controller | skipping: Conditional result was False 2025-12-04 00:31:07.825654 | 2025-12-04 00:31:07.825881 | PLAY [localhost] 2025-12-04 00:31:07.842751 | 2025-12-04 00:31:07.842835 | TASK [Run Zuul manifest role] 2025-12-04 00:31:07.863157 | localhost | ok 2025-12-04 00:31:07.879177 | 2025-12-04 00:31:07.879262 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-04 00:31:08.297208 | localhost | changed 2025-12-04 00:31:08.302198 | 2025-12-04 00:31:08.302269 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-04 00:31:08.331495 | localhost | ok 2025-12-04 00:31:08.339982 | 2025-12-04 00:31:08.340048 | TASK [Set zuul-log-path fact] 2025-12-04 00:31:08.358913 | localhost | ok 2025-12-04 00:31:08.374048 | 2025-12-04 00:31:08.374123 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-04 00:31:08.405109 | localhost | ok 2025-12-04 00:31:08.417042 | 2025-12-04 00:31:08.417134 | LOOP [Run upload-logs-swift role] 2025-12-04 00:31:08.457497 | localhost | Output suppressed because no_log was given 2025-12-04 00:31:08.492159 | 2025-12-04 00:31:08.492282 | TASK [Set zuul-log-path fact] 2025-12-04 00:31:08.517490 | localhost | skipping: Conditional result was False 2025-12-04 00:31:08.524395 | 2025-12-04 00:31:08.524484 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-04 00:31:08.979574 | localhost -> localhost | ok: Runtime: 0:00:00.012053 2025-12-04 00:31:09.021865 | 2025-12-04 00:31:09.022010 | TASK [upload-logs-swift : Upload logs to swift]