2026-02-07 00:21:38.825661 | Job console starting... 2026-02-07 00:21:38.837664 | Updating repositories 2026-02-07 00:21:38.993243 | Preparing job workspace 2026-02-07 00:21:43.073831 | Running Ansible setup... 2026-02-07 00:21:47.334211 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-07 00:21:47.970718 | 2026-02-07 00:21:47.970896 | PLAY [localhost] 2026-02-07 00:21:47.979667 | 2026-02-07 00:21:47.979791 | TASK [Gathering Facts] 2026-02-07 00:21:49.001169 | localhost | ok 2026-02-07 00:21:49.025666 | 2026-02-07 00:21:49.025808 | TASK [Setup log path fact] 2026-02-07 00:21:49.046521 | localhost | ok 2026-02-07 00:21:49.063724 | 2026-02-07 00:21:49.063833 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-07 00:21:49.106357 | localhost | ok 2026-02-07 00:21:49.121107 | 2026-02-07 00:21:49.121197 | TASK [emit-job-header : Print job information] 2026-02-07 00:21:49.151386 | # Job Information 2026-02-07 00:21:49.151542 | Ansible Version: 2.15.12 2026-02-07 00:21:49.151584 | Job: ansible-test-sanity-docker-devel 2026-02-07 00:21:49.151613 | Pipeline: periodic 2026-02-07 00:21:49.151639 | Executor: ze04.softwarefactory-project.io 2026-02-07 00:21:49.151664 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-07 00:21:49.151731 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/456/ansible/4560096deba645168c90b390a2a13279/ 2026-02-07 00:21:49.151762 | Event ID: debcfade88c04063a6272a678728f719 2026-02-07 00:21:49.156698 | 2026-02-07 00:21:49.156781 | LOOP [emit-job-header : Print node information] 2026-02-07 00:21:49.259376 | localhost | ok: 2026-02-07 00:21:49.259607 | localhost | # Node Information 2026-02-07 00:21:49.259673 | localhost | Inventory Hostname: controller 2026-02-07 00:21:49.259749 | localhost | Hostname: np0005611427 2026-02-07 00:21:49.259777 | localhost | Username: zuul 2026-02-07 00:21:49.259809 | localhost | Distro: Fedora 37 2026-02-07 00:21:49.259834 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-07 00:21:49.259858 | localhost | Region: ca-ymq-1 2026-02-07 00:21:49.259882 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-07 00:21:49.259905 | localhost | Product Name: OpenStack Nova 2026-02-07 00:21:49.259928 | localhost | Interface IP: 162.253.55.217 2026-02-07 00:21:49.280173 | 2026-02-07 00:21:49.280326 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-07 00:21:49.703903 | localhost -> localhost | changed 2026-02-07 00:21:49.710819 | 2026-02-07 00:21:49.710892 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-07 00:21:50.538168 | localhost -> localhost | changed 2026-02-07 00:21:50.557266 | 2026-02-07 00:21:50.557326 | PLAY [all:!appliance*] 2026-02-07 00:21:50.572992 | 2026-02-07 00:21:50.573057 | TASK [include_role : start-zuul-console] 2026-02-07 00:21:50.592308 | controller | ok 2026-02-07 00:21:50.606130 | 2026-02-07 00:21:50.606202 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-07 00:21:50.979657 | controller | ok 2026-02-07 00:21:51.006548 | 2026-02-07 00:21:51.006760 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-07 00:22:11.528365 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-07 00:22:11.544214 | 2026-02-07 00:22:11.544378 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-07 00:22:12.097663 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.113963 | 2026-02-07 00:22:12.114126 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-07 00:22:12.144126 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.159514 | 2026-02-07 00:22:12.159660 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-07 00:22:12.198651 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.212181 | 2026-02-07 00:22:12.212396 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-07 00:22:12.240856 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.255862 | 2026-02-07 00:22:12.256006 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-07 00:22:12.285055 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.302404 | 2026-02-07 00:22:12.302553 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-07 00:22:12.332331 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.359559 | 2026-02-07 00:22:12.359765 | TASK [Disable Fedora Modular] 2026-02-07 00:22:12.707061 | controller | changed 2026-02-07 00:22:12.722450 | 2026-02-07 00:22:12.722585 | TASK [Enable EPEL] 2026-02-07 00:22:12.750290 | controller | skipping: Conditional result was False 2026-02-07 00:22:12.770378 | 2026-02-07 00:22:12.770554 | TASK [Register the RHEL node] 2026-02-07 00:22:13.327566 | 2026-02-07 00:22:13.327749 | TASK [Show the subscription-manager status] 2026-02-07 00:22:13.886297 | controller | skipping: Conditional result was False 2026-02-07 00:22:13.895645 | 2026-02-07 00:22:13.895760 | TASK [Enable EPEL on RHEL] 2026-02-07 00:22:14.465473 | controller | skipping: Conditional result was False 2026-02-07 00:22:14.479307 | 2026-02-07 00:22:14.479450 | TASK [Install git and tox] 2026-02-07 00:23:11.059038 | controller | changed 2026-02-07 00:23:11.077763 | 2026-02-07 00:23:11.077923 | TASK [include_role : prepare-workspace] 2026-02-07 00:23:11.118437 | controller | ok 2026-02-07 00:23:11.155623 | 2026-02-07 00:23:11.155827 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-07 00:23:11.370213 | controller | ok 2026-02-07 00:23:11.377662 | 2026-02-07 00:23:11.377764 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-07 00:23:24.110109 | controller | Output suppressed because no_log was given 2026-02-07 00:23:24.123443 | 2026-02-07 00:23:24.123544 | TASK [include_role : prepare-workspace-openshift] 2026-02-07 00:23:24.142372 | controller | skipping: Conditional result was False 2026-02-07 00:23:24.171845 | 2026-02-07 00:23:24.171968 | PLAY [all:!appliance] 2026-02-07 00:23:24.188562 | 2026-02-07 00:23:24.188649 | TASK [Run add-build-sshkey role (RSA)] 2026-02-07 00:23:24.208697 | controller | ok 2026-02-07 00:23:24.224591 | 2026-02-07 00:23:24.224724 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-07 00:23:24.453927 | controller -> localhost | ok 2026-02-07 00:23:24.461890 | 2026-02-07 00:23:24.461963 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-07 00:23:24.492373 | controller | ok 2026-02-07 00:23:24.508715 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-07 00:23:24.515391 | 2026-02-07 00:23:24.515481 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-07 00:23:25.128663 | controller -> localhost | Generating public/private rsa key pair. 2026-02-07 00:23:25.128960 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_rsa. 2026-02-07 00:23:25.128992 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_rsa.pub. 2026-02-07 00:23:25.129015 | controller -> localhost | The key fingerprint is: 2026-02-07 00:23:25.129034 | controller -> localhost | SHA256:XFJamuQRmz2xmL3DqUXeMa2eb+JpcPvFWRS9aVbP0EA zuul-build-sshkey 2026-02-07 00:23:25.129053 | controller -> localhost | The key's randomart image is: 2026-02-07 00:23:25.129072 | controller -> localhost | +---[RSA 2048]----+ 2026-02-07 00:23:25.129091 | controller -> localhost | | +.+ .E+.| 2026-02-07 00:23:25.129109 | controller -> localhost | | o # o .. =| 2026-02-07 00:23:25.129127 | controller -> localhost | | @ B o .o*| 2026-02-07 00:23:25.129146 | controller -> localhost | | . * = + *o| 2026-02-07 00:23:25.129164 | controller -> localhost | | S B o o .| 2026-02-07 00:23:25.129193 | controller -> localhost | | o.o.. .o| 2026-02-07 00:23:25.129216 | controller -> localhost | | . oo. .o| 2026-02-07 00:23:25.129235 | controller -> localhost | | +o.. | 2026-02-07 00:23:25.129254 | controller -> localhost | | oo+o | 2026-02-07 00:23:25.129292 | controller -> localhost | +----[SHA256]-----+ 2026-02-07 00:23:25.129378 | controller -> localhost | ok: Runtime: 0:00:00.123330 2026-02-07 00:23:25.137014 | 2026-02-07 00:23:25.137084 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-07 00:23:25.168299 | controller | ok 2026-02-07 00:23:25.178137 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-07 00:23:25.187415 | 2026-02-07 00:23:25.187479 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-07 00:23:25.211698 | controller | skipping: Conditional result was False 2026-02-07 00:23:25.218427 | 2026-02-07 00:23:25.218492 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-07 00:23:25.654380 | controller | changed 2026-02-07 00:23:25.662958 | 2026-02-07 00:23:25.663039 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-07 00:23:25.896623 | controller | ok 2026-02-07 00:23:25.903881 | 2026-02-07 00:23:25.903985 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-07 00:23:26.534560 | controller | changed 2026-02-07 00:23:26.550953 | 2026-02-07 00:23:26.551087 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-07 00:23:27.223014 | controller | changed 2026-02-07 00:23:27.228941 | 2026-02-07 00:23:27.229009 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-07 00:23:27.253172 | controller | skipping: Conditional result was False 2026-02-07 00:23:27.259931 | 2026-02-07 00:23:27.260004 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-07 00:23:27.598235 | controller -> localhost | changed 2026-02-07 00:23:27.616597 | 2026-02-07 00:23:27.616954 | TASK [add-build-sshkey : Add back temp key] 2026-02-07 00:23:27.929260 | controller -> localhost | Identity added: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_rsa (zuul-build-sshkey) 2026-02-07 00:23:27.929528 | controller -> localhost | ok: Runtime: 0:00:00.013970 2026-02-07 00:23:27.951892 | 2026-02-07 00:23:27.955275 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-07 00:23:28.260697 | controller | ok 2026-02-07 00:23:28.267797 | 2026-02-07 00:23:28.267867 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-07 00:23:28.293000 | controller | skipping: Conditional result was False 2026-02-07 00:23:28.306387 | 2026-02-07 00:23:28.306475 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-07 00:23:28.327971 | controller | ok 2026-02-07 00:23:28.367580 | 2026-02-07 00:23:28.367751 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-07 00:23:28.630135 | controller -> localhost | ok 2026-02-07 00:23:28.636872 | 2026-02-07 00:23:28.636938 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-07 00:23:28.663406 | controller | ok 2026-02-07 00:23:28.675246 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-07 00:23:28.681500 | 2026-02-07 00:23:28.681585 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-07 00:23:28.959569 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-07 00:23:28.959773 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_ecdsa. 2026-02-07 00:23:28.959803 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_ecdsa.pub. 2026-02-07 00:23:28.959832 | controller -> localhost | The key fingerprint is: 2026-02-07 00:23:28.959852 | controller -> localhost | SHA256:G4dHEZWBo8WTm7HTkfKW/uqYssKayY2Xqe1vMBY5mN4 zuul-build-sshkey 2026-02-07 00:23:28.959871 | controller -> localhost | The key's randomart image is: 2026-02-07 00:23:28.959890 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-07 00:23:28.959908 | controller -> localhost | | .o=o+ | 2026-02-07 00:23:28.959926 | controller -> localhost | | X.+ | 2026-02-07 00:23:28.959943 | controller -> localhost | | o . o.@ o | 2026-02-07 00:23:28.959961 | controller -> localhost | | o + .o= = | 2026-02-07 00:23:28.959978 | controller -> localhost | | . . oS o+ | 2026-02-07 00:23:28.959995 | controller -> localhost | | . E = . | 2026-02-07 00:23:28.960012 | controller -> localhost | | o =. . | 2026-02-07 00:23:28.960029 | controller -> localhost | | . ** o o . | 2026-02-07 00:23:28.960046 | controller -> localhost | | B=++ooo.o. | 2026-02-07 00:23:28.960063 | controller -> localhost | +----[SHA256]-----+ 2026-02-07 00:23:28.960113 | controller -> localhost | ok: Runtime: 0:00:00.030269 2026-02-07 00:23:28.967040 | 2026-02-07 00:23:28.967104 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-07 00:23:28.988650 | controller | ok 2026-02-07 00:23:28.999429 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-07 00:23:29.020723 | 2026-02-07 00:23:29.020796 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-07 00:23:29.049934 | controller | skipping: Conditional result was False 2026-02-07 00:23:29.066305 | 2026-02-07 00:23:29.066723 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-07 00:23:29.336956 | controller | changed 2026-02-07 00:23:29.346823 | 2026-02-07 00:23:29.346917 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-07 00:23:29.554955 | controller | ok 2026-02-07 00:23:29.561565 | 2026-02-07 00:23:29.561640 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-07 00:23:30.240748 | controller | changed 2026-02-07 00:23:30.256835 | 2026-02-07 00:23:30.256984 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-07 00:23:30.897006 | controller | changed 2026-02-07 00:23:30.910841 | 2026-02-07 00:23:30.910993 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-07 00:23:30.935771 | controller | skipping: Conditional result was False 2026-02-07 00:23:30.946330 | 2026-02-07 00:23:30.946458 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-07 00:23:31.191017 | controller -> localhost | changed 2026-02-07 00:23:31.204131 | 2026-02-07 00:23:31.204199 | TASK [add-build-sshkey : Add back temp key] 2026-02-07 00:23:31.453029 | controller -> localhost | Identity added: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/4560096deba645168c90b390a2a13279_id_ecdsa (zuul-build-sshkey) 2026-02-07 00:23:31.453281 | controller -> localhost | ok: Runtime: 0:00:00.007872 2026-02-07 00:23:31.465156 | 2026-02-07 00:23:31.465242 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-07 00:23:31.722495 | controller | ok 2026-02-07 00:23:31.747803 | 2026-02-07 00:23:31.748157 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-07 00:23:31.780087 | controller | skipping: Conditional result was False 2026-02-07 00:23:31.808637 | 2026-02-07 00:23:31.808877 | TASK [include_role : remove-zuul-sshkey] 2026-02-07 00:23:31.837806 | controller | skipping: Conditional result was False 2026-02-07 00:23:31.850378 | 2026-02-07 00:23:31.850516 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-07 00:23:32.088797 | controller | ok: "logs" 2026-02-07 00:23:32.089091 | controller | ok: All items complete 2026-02-07 00:23:32.089130 | 2026-02-07 00:23:32.283566 | controller | ok: "artifacts" 2026-02-07 00:23:32.489182 | controller | ok: "docs" 2026-02-07 00:23:32.520997 | 2026-02-07 00:23:32.521094 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-07 00:23:32.770394 | controller | changed: "logs" 2026-02-07 00:23:32.966373 | controller | changed: "artifacts" 2026-02-07 00:23:33.182914 | controller | changed: "docs" 2026-02-07 00:23:33.254843 | 2026-02-07 00:23:33.254973 | PLAY RECAP 2026-02-07 00:23:33.255032 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-07 00:23:33.255069 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-07 00:23:33.255095 | 2026-02-07 00:23:33.399252 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-07 00:23:33.400863 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-07 00:23:33.991410 | 2026-02-07 00:23:33.991519 | PLAY [all] 2026-02-07 00:23:34.013112 | 2026-02-07 00:23:34.013202 | TASK [Install binary dependencies] 2026-02-07 00:23:34.061755 | controller | ok 2026-02-07 00:23:34.082375 | 2026-02-07 00:23:34.082464 | TASK [bindep : Include find tasks] 2026-02-07 00:23:34.121546 | controller | ok 2026-02-07 00:23:34.129745 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-07 00:23:34.136095 | 2026-02-07 00:23:34.136160 | TASK [bindep : Look for bindep.txt] 2026-02-07 00:23:34.494461 | controller | ok 2026-02-07 00:23:34.504578 | 2026-02-07 00:23:34.504758 | TASK [bindep : Define bindep_file fact] 2026-02-07 00:23:34.520578 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.530268 | 2026-02-07 00:23:34.530372 | TASK [bindep : Look for other-requirements.txt] 2026-02-07 00:23:34.734555 | controller | ok 2026-02-07 00:23:34.739993 | 2026-02-07 00:23:34.740061 | TASK [bindep : Define bindep_file fact] 2026-02-07 00:23:34.774737 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.780969 | 2026-02-07 00:23:34.781039 | TASK [bindep : Look for bindep fallback file] 2026-02-07 00:23:34.812935 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.823695 | 2026-02-07 00:23:34.823800 | TASK [bindep : Define bindep_file fact] 2026-02-07 00:23:34.849614 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.858457 | 2026-02-07 00:23:34.858553 | TASK [bindep : Include bindep tasks] 2026-02-07 00:23:34.883452 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.890401 | 2026-02-07 00:23:34.890467 | TASK [bindep : Include install tasks] 2026-02-07 00:23:34.914418 | controller | skipping: Conditional result was False 2026-02-07 00:23:34.921520 | 2026-02-07 00:23:34.921607 | LOOP [bindep : Include package tasks] 2026-02-07 00:23:34.988753 | 2026-02-07 00:23:34.988948 | TASK [Run test-setup role] 2026-02-07 00:23:35.013528 | controller | ok 2026-02-07 00:23:35.035330 | 2026-02-07 00:23:35.035450 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-07 00:23:35.256110 | controller | ok 2026-02-07 00:23:35.270953 | 2026-02-07 00:23:35.271094 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-07 00:23:35.821563 | controller | skipping: Conditional result was False 2026-02-07 00:23:35.880364 | 2026-02-07 00:23:35.880508 | PLAY RECAP 2026-02-07 00:23:35.880568 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-07 00:23:35.880595 | 2026-02-07 00:23:35.989015 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-07 00:23:35.991174 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-07 00:23:36.581594 | 2026-02-07 00:23:36.581765 | PLAY [controller] 2026-02-07 00:23:36.601840 | 2026-02-07 00:23:36.601920 | TASK [Create the /root directory] 2026-02-07 00:23:37.048024 | controller | ok 2026-02-07 00:23:37.056745 | 2026-02-07 00:23:37.056843 | TASK [Install glibc-langpack-en] 2026-02-07 00:23:41.101282 | controller | ok: Nothing to do 2026-02-07 00:23:41.116892 | 2026-02-07 00:23:41.117033 | TASK [Ensure controller directory exists] 2026-02-07 00:23:41.343372 | controller | changed 2026-02-07 00:23:41.351752 | 2026-02-07 00:23:41.351840 | TASK [Install container runtime] 2026-02-07 00:23:41.414025 | controller | ok 2026-02-07 00:23:41.459176 | 2026-02-07 00:23:41.459275 | LOOP [ensure-podman : Find distribution installation] 2026-02-07 00:23:41.493839 | controller | ok: "/var/lib/zuul/builds/4560096deba645168c90b390a2a13279/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-07 00:23:41.500676 | controller | included: /var/lib/zuul/builds/4560096deba645168c90b390a2a13279/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-07 00:23:41.506969 | 2026-02-07 00:23:41.507033 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-07 00:24:52.307252 | controller | changed 2026-02-07 00:24:52.313534 | 2026-02-07 00:24:52.313598 | TASK [ensure-podman : Fetch podman version] 2026-02-07 00:24:52.998805 | controller | Client: Podman Engine 2026-02-07 00:24:53.024562 | controller | Version: 4.6.2 2026-02-07 00:24:53.024603 | controller | API Version: 4.6.2 2026-02-07 00:24:53.024615 | controller | Go Version: go1.19.12 2026-02-07 00:24:53.024640 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-07 00:24:53.024675 | controller | OS/Arch: linux/amd64 2026-02-07 00:24:53.344384 | controller | ok: Runtime: 0:00:00.322417 2026-02-07 00:24:53.359347 | 2026-02-07 00:24:53.359514 | TASK [ensure-podman : Print podman version installed] 2026-02-07 00:24:53.399556 | Podman version: Client: Podman Engine 2026-02-07 00:24:53.400277 | Version: 4.6.2 2026-02-07 00:24:53.400354 | API Version: 4.6.2 2026-02-07 00:24:53.400399 | Go Version: go1.19.12 2026-02-07 00:24:53.400438 | Built: Mon Aug 28 19:38:31 2023 2026-02-07 00:24:53.400481 | OS/Arch: linux/amd64 2026-02-07 00:24:53.415964 | 2026-02-07 00:24:53.416112 | TASK [ensure-podman : Validate podman engine] 2026-02-07 00:24:53.959636 | controller | skipping: Conditional result was False 2026-02-07 00:24:53.968949 | 2026-02-07 00:24:53.969044 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-07 00:24:53.994346 | controller | skipping: Conditional result was False 2026-02-07 00:24:54.011024 | 2026-02-07 00:24:54.011132 | TASK [Ensure python3.8 is present] 2026-02-07 00:24:54.046670 | controller | skipping: Conditional result was False 2026-02-07 00:24:54.053079 | 2026-02-07 00:24:54.053143 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-07 00:24:54.081958 | controller | ok 2026-02-07 00:24:54.100941 | 2026-02-07 00:24:54.101012 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-07 00:24:55.818715 | controller | ok: Nothing to do 2026-02-07 00:24:55.835239 | 2026-02-07 00:24:55.835416 | TASK [our-ensure-python : Also install python3-devel] 2026-02-07 00:25:10.876947 | controller | changed 2026-02-07 00:25:10.900963 | 2026-02-07 00:25:10.901205 | TASK [Run ensure-virtualenv role] 2026-02-07 00:25:10.923824 | controller | ok 2026-02-07 00:25:10.952651 | 2026-02-07 00:25:10.952799 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-07 00:25:11.222047 | controller | /usr/bin/virtualenv 2026-02-07 00:25:11.515901 | controller | ok: Runtime: 0:00:00.006770 2026-02-07 00:25:11.524322 | 2026-02-07 00:25:11.524449 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-07 00:25:11.558377 | controller | skipping: Conditional result was False 2026-02-07 00:25:11.558831 | controller | ok: All items complete 2026-02-07 00:25:11.558890 | 2026-02-07 00:25:11.595629 | 2026-02-07 00:25:11.595879 | TASK [Find the full path of the Python interpreter] 2026-02-07 00:25:11.831310 | controller | /usr/bin/python3 2026-02-07 00:25:12.139989 | controller | ok 2026-02-07 00:25:12.152644 | 2026-02-07 00:25:12.152809 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-07 00:25:13.038463 | controller | created virtual environment CPython3.11.0.final.0-64 in 481ms 2026-02-07 00:25:13.065307 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-07 00:25:13.065347 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-02-07 00:25:13.065357 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-07 00:25:13.065373 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-07 00:25:13.208380 | controller | changed 2026-02-07 00:25:13.222433 | 2026-02-07 00:25:13.222600 | TASK [Set selinux package] 2026-02-07 00:25:13.262130 | controller | ok 2026-02-07 00:25:13.274457 | 2026-02-07 00:25:13.274619 | TASK [Set selinux package (Fedora)] 2026-02-07 00:25:13.325747 | controller | ok 2026-02-07 00:25:13.339130 | 2026-02-07 00:25:13.339260 | TASK [Install selinux into virtualenv] 2026-02-07 00:25:26.966035 | controller | Collecting selinux-please-lie-to-me 2026-02-07 00:25:39.227813 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-07 00:25:39.533843 | controller | Collecting setuptools<50.0.0 2026-02-07 00:25:39.544093 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-07 00:25:39.604538 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.1 MB/s eta 0:00:00 2026-02-07 00:25:39.685952 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-07 00:25:39.686168 | controller | Attempting uninstall: setuptools 2026-02-07 00:25:39.688793 | controller | Found existing installation: setuptools 62.6.0 2026-02-07 00:25:39.749200 | controller | Uninstalling setuptools-62.6.0: 2026-02-07 00:25:39.758576 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-07 00:25:40.136753 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-07 00:25:51.601495 | controller | 2026-02-07 00:25:51.706880 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-07 00:25:51.706936 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-07 00:25:51.921620 | controller | ok: Runtime: 0:00:38.134595 2026-02-07 00:25:51.929565 | 2026-02-07 00:25:51.929649 | TASK [Install pytest-forked into virtualenv] 2026-02-07 00:26:03.846135 | controller | Collecting pytest-forked 2026-02-07 00:26:16.090062 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-07 00:26:16.134493 | controller | Collecting py 2026-02-07 00:26:16.142407 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-07 00:26:16.161490 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.1 MB/s eta 0:00:00 2026-02-07 00:26:16.270488 | controller | Collecting pytest>=3.10 2026-02-07 00:26:16.276368 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-07 00:26:16.290478 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.5 MB/s eta 0:00:00 2026-02-07 00:26:16.328330 | controller | Collecting iniconfig>=1.0.1 2026-02-07 00:26:16.332783 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-07 00:26:16.378766 | controller | Collecting packaging>=22 2026-02-07 00:26:16.382076 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-07 00:26:16.387063 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 22.5 MB/s eta 0:00:00 2026-02-07 00:26:16.419487 | controller | Collecting pluggy<2,>=1.5 2026-02-07 00:26:16.424415 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-07 00:26:16.473183 | controller | Collecting pygments>=2.7.2 2026-02-07 00:26:16.482487 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-07 00:26:16.521307 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 35.3 MB/s eta 0:00:00 2026-02-07 00:26:16.591279 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-07 00:26:17.721270 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-07 00:26:17.731107 | controller | 2026-02-07 00:26:17.814356 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-07 00:26:17.814390 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-07 00:26:17.973983 | controller | ok: Runtime: 0:00:25.688991 2026-02-07 00:26:17.988030 | 2026-02-07 00:26:17.988194 | TASK [Update pip] 2026-02-07 00:26:18.562221 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-07 00:26:28.475085 | controller | Collecting pip 2026-02-07 00:26:40.667340 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-07 00:26:40.751287 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 22.2 MB/s eta 0:00:00 2026-02-07 00:26:40.831799 | controller | Installing collected packages: pip 2026-02-07 00:26:40.832047 | controller | Attempting uninstall: pip 2026-02-07 00:26:40.834526 | controller | Found existing installation: pip 22.2.2 2026-02-07 00:26:40.972473 | controller | Uninstalling pip-22.2.2: 2026-02-07 00:26:40.988147 | controller | Successfully uninstalled pip-22.2.2 2026-02-07 00:26:41.823912 | controller | Successfully installed pip-26.0.1 2026-02-07 00:26:42.060972 | controller | ok: Runtime: 0:00:23.665376 2026-02-07 00:26:42.074910 | 2026-02-07 00:26:42.075060 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-07 00:26:42.308628 | controller | changed 2026-02-07 00:26:42.322480 | 2026-02-07 00:26:42.322719 | TASK [Install ansible into virtualenv] 2026-02-07 00:26:42.880147 | controller | Processing ./src/github.com/ansible/ansible 2026-02-07 00:26:42.882519 | controller | Installing build dependencies: started 2026-02-07 00:27:03.532571 | controller | Installing build dependencies: finished with status 'done' 2026-02-07 00:27:03.533314 | controller | Getting requirements to build wheel: started 2026-02-07 00:27:04.288967 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-07 00:27:04.289794 | controller | Preparing metadata (pyproject.toml): started 2026-02-07 00:27:04.742919 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-07 00:27:04.748038 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-02-07 00:27:04.753549 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-07 00:27:04.910436 | controller | ERROR 2026-02-07 00:27:04.910667 | controller | { 2026-02-07 00:27:04.910783 | controller | "delta": "0:00:22.216364", 2026-02-07 00:27:04.910830 | controller | "end": "2026-02-07 00:27:04.814041", 2026-02-07 00:27:04.910873 | controller | "msg": "non-zero return code", 2026-02-07 00:27:04.910927 | controller | "rc": 1, 2026-02-07 00:27:04.910968 | controller | "start": "2026-02-07 00:26:42.597677" 2026-02-07 00:27:04.911008 | controller | } failure 2026-02-07 00:27:04.914003 | 2026-02-07 00:27:04.914157 | PLAY RECAP 2026-02-07 00:27:04.914251 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-07 00:27:04.914296 | 2026-02-07 00:27:05.047797 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-07 00:27:05.049033 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-07 00:27:05.750243 | 2026-02-07 00:27:05.750500 | PLAY [all] 2026-02-07 00:27:05.778402 | 2026-02-07 00:27:05.778656 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-07 00:27:06.061321 | controller | changed: non-zero return code 2026-02-07 00:27:06.068652 | 2026-02-07 00:27:06.068837 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-07 00:27:06.097499 | controller | skipping: Conditional result was False 2026-02-07 00:27:06.105603 | 2026-02-07 00:27:06.105756 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-07 00:27:06.132709 | 2026-02-07 00:27:06.132932 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-07 00:27:06.159391 | 2026-02-07 00:27:06.159653 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-07 00:27:06.176236 | controller | skipping: Conditional result was False 2026-02-07 00:27:06.187192 | 2026-02-07 00:27:06.187373 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-07 00:27:06.222138 | 2026-02-07 00:27:06.222388 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-07 00:27:06.239611 | controller | skipping: Conditional result was False 2026-02-07 00:27:06.249230 | 2026-02-07 00:27:06.249328 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-07 00:27:06.267332 | controller | skipping: Conditional result was False 2026-02-07 00:27:06.281854 | 2026-02-07 00:27:06.282004 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-07 00:27:06.298868 | controller | skipping: Conditional result was False 2026-02-07 00:27:06.346609 | 2026-02-07 00:27:06.346725 | PLAY RECAP 2026-02-07 00:27:06.346793 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-07 00:27:06.346821 | 2026-02-07 00:27:06.460776 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-07 00:27:06.462653 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-07 00:27:07.012776 | 2026-02-07 00:27:07.012898 | PLAY [all:!appliance*] 2026-02-07 00:27:07.035028 | 2026-02-07 00:27:07.035106 | TASK [unregister the node] 2026-02-07 00:27:07.565708 | controller | skipping: Conditional result was False 2026-02-07 00:27:07.573941 | 2026-02-07 00:27:07.574050 | TASK [include_role : fetch-output] 2026-02-07 00:27:07.621542 | controller | ok 2026-02-07 00:27:07.658795 | 2026-02-07 00:27:07.658922 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-07 00:27:07.735073 | controller | skipping: Conditional result was False 2026-02-07 00:27:07.744566 | 2026-02-07 00:27:07.744673 | TASK [fetch-output : Set log path for single node] 2026-02-07 00:27:07.791520 | controller | ok 2026-02-07 00:27:07.803740 | 2026-02-07 00:27:07.803957 | LOOP [fetch-output : Ensure local output dirs] 2026-02-07 00:27:08.179240 | controller -> localhost | ok: "/var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/logs" 2026-02-07 00:27:08.470110 | controller -> localhost | changed: "/var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/artifacts" 2026-02-07 00:27:08.748080 | controller -> localhost | changed: "/var/lib/zuul/builds/4560096deba645168c90b390a2a13279/work/docs" 2026-02-07 00:27:08.774154 | 2026-02-07 00:27:08.774323 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-07 00:27:09.383343 | controller | changed: 2026-02-07 00:27:09.383799 | controller | .d..t...... ./ 2026-02-07 00:27:09.383879 | controller | cd+++++++++ controller/ 2026-02-07 00:27:09.383950 | controller | changed: All items complete 2026-02-07 00:27:09.383995 | 2026-02-07 00:27:09.819283 | controller | changed: .d..t...... ./ 2026-02-07 00:27:10.329349 | controller | changed: .d..t...... ./ 2026-02-07 00:27:10.356572 | 2026-02-07 00:27:10.356736 | TASK [include_role : fetch-output-openshift] 2026-02-07 00:27:10.371166 | controller | skipping: Conditional result was False 2026-02-07 00:27:10.380740 | 2026-02-07 00:27:10.380835 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-07 00:27:10.407078 | controller | skipping: Conditional result was False 2026-02-07 00:27:10.416283 | controller | skipping: Conditional result was False 2026-02-07 00:27:10.463877 | 2026-02-07 00:27:10.464133 | PLAY [localhost] 2026-02-07 00:27:10.481104 | 2026-02-07 00:27:10.481186 | TASK [Run Zuul manifest role] 2026-02-07 00:27:10.499364 | localhost | ok 2026-02-07 00:27:10.513515 | 2026-02-07 00:27:10.513579 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-07 00:27:10.839802 | localhost | changed 2026-02-07 00:27:10.844389 | 2026-02-07 00:27:10.844452 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-07 00:27:10.872795 | localhost | ok 2026-02-07 00:27:10.880692 | 2026-02-07 00:27:10.880754 | TASK [Set zuul-log-path fact] 2026-02-07 00:27:10.898366 | localhost | ok 2026-02-07 00:27:10.912133 | 2026-02-07 00:27:10.912196 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-07 00:27:10.940202 | localhost | ok 2026-02-07 00:27:10.948439 | 2026-02-07 00:27:10.948496 | LOOP [Run upload-logs-swift role] 2026-02-07 00:27:10.972151 | localhost | Output suppressed because no_log was given 2026-02-07 00:27:10.997275 | 2026-02-07 00:27:10.997372 | TASK [Set zuul-log-path fact] 2026-02-07 00:27:11.031797 | localhost | skipping: Conditional result was False 2026-02-07 00:27:11.037254 | 2026-02-07 00:27:11.037322 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-07 00:27:11.420220 | localhost -> localhost | ok: Runtime: 0:00:00.006929 2026-02-07 00:27:11.453050 | 2026-02-07 00:27:11.453184 | TASK [upload-logs-swift : Upload logs to swift]