2026-02-19 00:06:49.487980 | Job console starting... 2026-02-19 00:06:49.496851 | Updating repositories 2026-02-19 00:06:49.611976 | Preparing job workspace 2026-02-19 00:06:57.609480 | Running Ansible setup... 2026-02-19 00:07:04.473591 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-19 00:07:05.104012 | 2026-02-19 00:07:05.104151 | PLAY [localhost] 2026-02-19 00:07:05.127507 | 2026-02-19 00:07:05.127641 | TASK [Gathering Facts] 2026-02-19 00:07:06.136306 | localhost | ok 2026-02-19 00:07:06.161518 | 2026-02-19 00:07:06.161777 | TASK [Setup log path fact] 2026-02-19 00:07:06.181340 | localhost | ok 2026-02-19 00:07:06.195241 | 2026-02-19 00:07:06.195386 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-19 00:07:06.223979 | localhost | ok 2026-02-19 00:07:06.232411 | 2026-02-19 00:07:06.232496 | TASK [emit-job-header : Print job information] 2026-02-19 00:07:06.271243 | # Job Information 2026-02-19 00:07:06.271399 | Ansible Version: 2.15.12 2026-02-19 00:07:06.271430 | Job: ansible-test-sanity-docker-devel 2026-02-19 00:07:06.271451 | Pipeline: periodic 2026-02-19 00:07:06.271470 | Executor: ze03.softwarefactory-project.io 2026-02-19 00:07:06.271490 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-19 00:07:06.271511 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/39a/ansible/39a624b08703485c8b222a29609829bf/ 2026-02-19 00:07:06.271530 | Event ID: d77a250cf7fd40868fb03f0c570040ac 2026-02-19 00:07:06.275643 | 2026-02-19 00:07:06.275709 | LOOP [emit-job-header : Print node information] 2026-02-19 00:07:06.394038 | localhost | ok: 2026-02-19 00:07:06.394330 | localhost | # Node Information 2026-02-19 00:07:06.394393 | localhost | Inventory Hostname: controller 2026-02-19 00:07:06.394438 | localhost | Hostname: np0005623847 2026-02-19 00:07:06.394480 | localhost | Username: zuul 2026-02-19 00:07:06.394685 | localhost | Distro: Fedora 37 2026-02-19 00:07:06.394794 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-19 00:07:06.394857 | localhost | Region: ca-ymq-1 2026-02-19 00:07:06.394926 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-19 00:07:06.395041 | localhost | Product Name: OpenStack Nova 2026-02-19 00:07:06.395092 | localhost | Interface IP: 162.253.55.62 2026-02-19 00:07:06.416980 | 2026-02-19 00:07:06.417207 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-19 00:07:06.910911 | localhost -> localhost | changed 2026-02-19 00:07:06.916761 | 2026-02-19 00:07:06.916838 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-19 00:07:07.932200 | localhost -> localhost | changed 2026-02-19 00:07:07.955099 | 2026-02-19 00:07:07.955214 | PLAY [all:!appliance*] 2026-02-19 00:07:07.976398 | 2026-02-19 00:07:07.976512 | TASK [include_role : start-zuul-console] 2026-02-19 00:07:07.997306 | controller | ok 2026-02-19 00:07:08.011423 | 2026-02-19 00:07:08.011501 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-19 00:07:08.398451 | controller | ok 2026-02-19 00:07:08.414643 | 2026-02-19 00:07:08.414845 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-19 00:07:09.214328 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-19 00:07:09.230756 | 2026-02-19 00:07:09.230907 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-19 00:07:09.767346 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.781767 | 2026-02-19 00:07:09.781969 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-19 00:07:09.830758 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.842885 | 2026-02-19 00:07:09.843036 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-19 00:07:09.869030 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.880498 | 2026-02-19 00:07:09.880717 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-19 00:07:09.907734 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.919782 | 2026-02-19 00:07:09.919952 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-19 00:07:09.946053 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.954848 | 2026-02-19 00:07:09.954964 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-19 00:07:09.979809 | controller | skipping: Conditional result was False 2026-02-19 00:07:09.993308 | 2026-02-19 00:07:09.993439 | TASK [Disable Fedora Modular] 2026-02-19 00:07:10.249620 | controller | changed 2026-02-19 00:07:10.256079 | 2026-02-19 00:07:10.256155 | TASK [Enable EPEL] 2026-02-19 00:07:10.271078 | controller | skipping: Conditional result was False 2026-02-19 00:07:10.278162 | 2026-02-19 00:07:10.278290 | TASK [Register the RHEL node] 2026-02-19 00:07:10.821350 | 2026-02-19 00:07:10.821517 | TASK [Show the subscription-manager status] 2026-02-19 00:07:11.393646 | controller | skipping: Conditional result was False 2026-02-19 00:07:11.403401 | 2026-02-19 00:07:11.403530 | TASK [Enable EPEL on RHEL] 2026-02-19 00:07:11.952135 | controller | skipping: Conditional result was False 2026-02-19 00:07:11.962016 | 2026-02-19 00:07:11.962149 | TASK [Install git and tox] 2026-02-19 00:08:43.608124 | controller | changed 2026-02-19 00:08:43.627669 | 2026-02-19 00:08:43.627840 | TASK [include_role : prepare-workspace] 2026-02-19 00:08:43.654560 | controller | ok 2026-02-19 00:08:43.720613 | 2026-02-19 00:08:43.720757 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-19 00:08:43.967851 | controller | ok 2026-02-19 00:08:43.976863 | 2026-02-19 00:08:43.977211 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-19 00:14:46.751277 | controller | Output suppressed because no_log was given 2026-02-19 00:14:46.766237 | 2026-02-19 00:14:46.766377 | TASK [include_role : prepare-workspace-openshift] 2026-02-19 00:14:46.791869 | controller | skipping: Conditional result was False 2026-02-19 00:14:46.814489 | 2026-02-19 00:14:46.814565 | PLAY [all:!appliance] 2026-02-19 00:14:46.830859 | 2026-02-19 00:14:46.830991 | TASK [Run add-build-sshkey role (RSA)] 2026-02-19 00:14:46.871242 | controller | ok 2026-02-19 00:14:46.888036 | 2026-02-19 00:14:46.888153 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-19 00:14:47.116397 | controller -> localhost | ok 2026-02-19 00:14:47.123083 | 2026-02-19 00:14:47.123179 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-19 00:14:47.146966 | controller | ok 2026-02-19 00:14:47.166545 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-19 00:14:47.174884 | 2026-02-19 00:14:47.175024 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-19 00:14:47.710982 | controller -> localhost | Generating public/private rsa key pair. 2026-02-19 00:14:47.711207 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_rsa. 2026-02-19 00:14:47.711238 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_rsa.pub. 2026-02-19 00:14:47.711260 | controller -> localhost | The key fingerprint is: 2026-02-19 00:14:47.711280 | controller -> localhost | SHA256:ue3ohp/SGH6Qe9YLnWcFjP5AMtdfC4n/5busbCYiOsc zuul-build-sshkey 2026-02-19 00:14:47.711299 | controller -> localhost | The key's randomart image is: 2026-02-19 00:14:47.711317 | controller -> localhost | +---[RSA 2048]----+ 2026-02-19 00:14:47.711336 | controller -> localhost | | | 2026-02-19 00:14:47.711355 | controller -> localhost | | +. . | 2026-02-19 00:14:47.711373 | controller -> localhost | | o +.+o .| 2026-02-19 00:14:47.711391 | controller -> localhost | | B .o...| 2026-02-19 00:14:47.711408 | controller -> localhost | | .S o .o..| 2026-02-19 00:14:47.711436 | controller -> localhost | | + + + ....| 2026-02-19 00:14:47.711458 | controller -> localhost | | ..Bo.+ + ..| 2026-02-19 00:14:47.711478 | controller -> localhost | | .*E**.+.o. .| 2026-02-19 00:14:47.711497 | controller -> localhost | | .+O* +.+o.+.| 2026-02-19 00:14:47.711518 | controller -> localhost | +----[SHA256]-----+ 2026-02-19 00:14:47.711570 | controller -> localhost | ok: Runtime: 0:00:00.097140 2026-02-19 00:14:47.732050 | 2026-02-19 00:14:47.732218 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-19 00:14:47.786621 | controller | ok 2026-02-19 00:14:47.804117 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-19 00:14:47.818900 | 2026-02-19 00:14:47.819051 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-19 00:14:47.843777 | controller | skipping: Conditional result was False 2026-02-19 00:14:47.850953 | 2026-02-19 00:14:47.851087 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-19 00:14:48.479525 | controller | changed 2026-02-19 00:14:48.490338 | 2026-02-19 00:14:48.490794 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-19 00:14:48.718580 | controller | ok 2026-02-19 00:14:48.724339 | 2026-02-19 00:14:48.724403 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-19 00:14:49.347439 | controller | changed 2026-02-19 00:14:49.354579 | 2026-02-19 00:14:49.354679 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-19 00:14:49.982034 | controller | changed 2026-02-19 00:14:49.990579 | 2026-02-19 00:14:49.990720 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-19 00:14:50.026674 | controller | skipping: Conditional result was False 2026-02-19 00:14:50.035554 | 2026-02-19 00:14:50.035664 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-19 00:14:50.511314 | controller -> localhost | changed 2026-02-19 00:14:50.524297 | 2026-02-19 00:14:50.524422 | TASK [add-build-sshkey : Add back temp key] 2026-02-19 00:14:50.804531 | controller -> localhost | Identity added: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_rsa (zuul-build-sshkey) 2026-02-19 00:14:50.804773 | controller -> localhost | ok: Runtime: 0:00:00.008269 2026-02-19 00:14:50.811703 | 2026-02-19 00:14:50.811795 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-19 00:14:51.617308 | controller | ok 2026-02-19 00:14:51.624322 | 2026-02-19 00:14:51.624448 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-19 00:14:51.649025 | controller | skipping: Conditional result was False 2026-02-19 00:14:51.664610 | 2026-02-19 00:14:51.664747 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-19 00:14:51.686119 | controller | ok 2026-02-19 00:14:51.706281 | 2026-02-19 00:14:51.706411 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-19 00:14:51.947705 | controller -> localhost | ok 2026-02-19 00:14:51.954390 | 2026-02-19 00:14:51.954482 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-19 00:14:51.985250 | controller | ok 2026-02-19 00:14:51.999008 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-19 00:14:52.005996 | 2026-02-19 00:14:52.006094 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-19 00:14:52.280791 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-19 00:14:52.281003 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_ecdsa. 2026-02-19 00:14:52.281036 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_ecdsa.pub. 2026-02-19 00:14:52.281070 | controller -> localhost | The key fingerprint is: 2026-02-19 00:14:52.281095 | controller -> localhost | SHA256:jA77unrqObk4dzLDAezd3Dc8Na0ZWwVsfkJcDDDLANs zuul-build-sshkey 2026-02-19 00:14:52.281118 | controller -> localhost | The key's randomart image is: 2026-02-19 00:14:52.281157 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-19 00:14:52.281181 | controller -> localhost | | ... o+o=. | 2026-02-19 00:14:52.281203 | controller -> localhost | | o o o= o | 2026-02-19 00:14:52.281225 | controller -> localhost | |. . E o= . | 2026-02-19 00:14:52.281300 | controller -> localhost | |.. o + = . | 2026-02-19 00:14:52.281324 | controller -> localhost | |... + o S . B o | 2026-02-19 00:14:52.281345 | controller -> localhost | | ... * . = + | 2026-02-19 00:14:52.281366 | controller -> localhost | | . o. . . o | 2026-02-19 00:14:52.281387 | controller -> localhost | |..O.o. | 2026-02-19 00:14:52.281408 | controller -> localhost | |.+*@oo. | 2026-02-19 00:14:52.281429 | controller -> localhost | +----[SHA256]-----+ 2026-02-19 00:14:52.281482 | controller -> localhost | ok: Runtime: 0:00:00.008446 2026-02-19 00:14:52.288830 | 2026-02-19 00:14:52.288938 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-19 00:14:52.310358 | controller | ok 2026-02-19 00:14:52.319231 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-19 00:14:52.331053 | 2026-02-19 00:14:52.331319 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-19 00:14:52.355878 | controller | skipping: Conditional result was False 2026-02-19 00:14:52.363974 | 2026-02-19 00:14:52.364105 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-19 00:14:52.629672 | controller | changed 2026-02-19 00:14:52.641022 | 2026-02-19 00:14:52.641130 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-19 00:14:52.859244 | controller | ok 2026-02-19 00:14:52.868547 | 2026-02-19 00:14:52.868689 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-19 00:14:53.489001 | controller | changed 2026-02-19 00:14:53.495091 | 2026-02-19 00:14:53.495195 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-19 00:14:54.123834 | controller | changed 2026-02-19 00:14:54.133636 | 2026-02-19 00:14:54.133826 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-19 00:14:54.159824 | controller | skipping: Conditional result was False 2026-02-19 00:14:54.170682 | 2026-02-19 00:14:54.170874 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-19 00:14:54.421719 | controller -> localhost | changed 2026-02-19 00:14:54.443305 | 2026-02-19 00:14:54.443455 | TASK [add-build-sshkey : Add back temp key] 2026-02-19 00:14:54.776068 | controller -> localhost | Identity added: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/39a624b08703485c8b222a29609829bf_id_ecdsa (zuul-build-sshkey) 2026-02-19 00:14:54.776314 | controller -> localhost | ok: Runtime: 0:00:00.017827 2026-02-19 00:14:54.784512 | 2026-02-19 00:14:54.784631 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-19 00:14:55.002319 | controller | ok 2026-02-19 00:14:55.011516 | 2026-02-19 00:14:55.011660 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-19 00:14:55.047575 | controller | skipping: Conditional result was False 2026-02-19 00:14:55.067444 | 2026-02-19 00:14:55.067593 | TASK [include_role : remove-zuul-sshkey] 2026-02-19 00:14:55.093448 | controller | skipping: Conditional result was False 2026-02-19 00:14:55.103633 | 2026-02-19 00:14:55.103761 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-19 00:14:55.341279 | controller | ok: "logs" 2026-02-19 00:14:55.341570 | controller | ok: All items complete 2026-02-19 00:14:55.341609 | 2026-02-19 00:14:55.527884 | controller | ok: "artifacts" 2026-02-19 00:14:55.723669 | controller | ok: "docs" 2026-02-19 00:14:55.737834 | 2026-02-19 00:14:55.737980 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-19 00:14:55.993185 | controller | changed: "logs" 2026-02-19 00:14:56.187054 | controller | changed: "artifacts" 2026-02-19 00:14:56.388628 | controller | changed: "docs" 2026-02-19 00:14:56.435100 | 2026-02-19 00:14:56.435270 | PLAY RECAP 2026-02-19 00:14:56.435333 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-19 00:14:56.435371 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-19 00:14:56.435398 | 2026-02-19 00:14:56.570517 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-19 00:14:56.571476 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-19 00:14:57.270457 | 2026-02-19 00:14:57.270645 | PLAY [all] 2026-02-19 00:14:57.298247 | 2026-02-19 00:14:57.298391 | TASK [Install binary dependencies] 2026-02-19 00:14:57.360178 | controller | ok 2026-02-19 00:14:57.384164 | 2026-02-19 00:14:57.384312 | TASK [bindep : Include find tasks] 2026-02-19 00:14:57.414985 | controller | ok 2026-02-19 00:14:57.424090 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-19 00:14:57.431749 | 2026-02-19 00:14:57.431882 | TASK [bindep : Look for bindep.txt] 2026-02-19 00:14:58.016417 | controller | ok 2026-02-19 00:14:58.025981 | 2026-02-19 00:14:58.026108 | TASK [bindep : Define bindep_file fact] 2026-02-19 00:14:58.040673 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.047642 | 2026-02-19 00:14:58.047745 | TASK [bindep : Look for other-requirements.txt] 2026-02-19 00:14:58.257429 | controller | ok 2026-02-19 00:14:58.266273 | 2026-02-19 00:14:58.266424 | TASK [bindep : Define bindep_file fact] 2026-02-19 00:14:58.291480 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.299342 | 2026-02-19 00:14:58.299479 | TASK [bindep : Look for bindep fallback file] 2026-02-19 00:14:58.339401 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.347334 | 2026-02-19 00:14:58.347485 | TASK [bindep : Define bindep_file fact] 2026-02-19 00:14:58.371747 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.378529 | 2026-02-19 00:14:58.378651 | TASK [bindep : Include bindep tasks] 2026-02-19 00:14:58.405716 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.415714 | 2026-02-19 00:14:58.415901 | TASK [bindep : Include install tasks] 2026-02-19 00:14:58.441888 | controller | skipping: Conditional result was False 2026-02-19 00:14:58.452144 | 2026-02-19 00:14:58.452310 | LOOP [bindep : Include package tasks] 2026-02-19 00:14:58.521288 | 2026-02-19 00:14:58.521500 | TASK [Run test-setup role] 2026-02-19 00:14:58.544261 | controller | ok 2026-02-19 00:14:58.565839 | 2026-02-19 00:14:58.565968 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-19 00:14:58.762406 | controller | ok 2026-02-19 00:14:58.773781 | 2026-02-19 00:14:58.773906 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-19 00:14:59.326121 | controller | skipping: Conditional result was False 2026-02-19 00:14:59.355515 | 2026-02-19 00:14:59.355619 | PLAY RECAP 2026-02-19 00:14:59.355660 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-19 00:14:59.355680 | 2026-02-19 00:14:59.471629 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-19 00:14:59.472624 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-19 00:15:00.114288 | 2026-02-19 00:15:00.114471 | PLAY [controller] 2026-02-19 00:15:00.136145 | 2026-02-19 00:15:00.136292 | TASK [Create the /root directory] 2026-02-19 00:15:00.699079 | controller | ok 2026-02-19 00:15:00.705217 | 2026-02-19 00:15:00.705348 | TASK [Install glibc-langpack-en] 2026-02-19 00:15:04.574695 | controller | ok: Nothing to do 2026-02-19 00:15:04.585138 | 2026-02-19 00:15:04.585277 | TASK [Ensure controller directory exists] 2026-02-19 00:15:04.784825 | controller | changed 2026-02-19 00:15:04.795492 | 2026-02-19 00:15:04.795680 | TASK [Install container runtime] 2026-02-19 00:15:04.840935 | controller | ok 2026-02-19 00:15:04.883348 | 2026-02-19 00:15:04.883491 | LOOP [ensure-podman : Find distribution installation] 2026-02-19 00:15:04.909892 | controller | ok: "/var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-19 00:15:04.929425 | controller | included: /var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-19 00:15:04.938157 | 2026-02-19 00:15:04.938295 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-19 00:16:10.220000 | controller | changed 2026-02-19 00:16:10.230455 | 2026-02-19 00:16:10.230607 | TASK [ensure-podman : Fetch podman version] 2026-02-19 00:16:10.792252 | controller | Client: Podman Engine 2026-02-19 00:16:10.792343 | controller | Version: 4.6.2 2026-02-19 00:16:10.792387 | controller | API Version: 4.6.2 2026-02-19 00:16:10.792427 | controller | Go Version: go1.19.12 2026-02-19 00:16:10.792479 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-19 00:16:10.792520 | controller | OS/Arch: linux/amd64 2026-02-19 00:16:11.281019 | controller | ok: Runtime: 0:00:00.203044 2026-02-19 00:16:11.288861 | 2026-02-19 00:16:11.288972 | TASK [ensure-podman : Print podman version installed] 2026-02-19 00:16:11.320015 | Podman version: Client: Podman Engine 2026-02-19 00:16:11.320227 | Version: 4.6.2 2026-02-19 00:16:11.320271 | API Version: 4.6.2 2026-02-19 00:16:11.320294 | Go Version: go1.19.12 2026-02-19 00:16:11.320313 | Built: Mon Aug 28 19:38:31 2023 2026-02-19 00:16:11.320333 | OS/Arch: linux/amd64 2026-02-19 00:16:11.327456 | 2026-02-19 00:16:11.327573 | TASK [ensure-podman : Validate podman engine] 2026-02-19 00:16:11.862782 | controller | skipping: Conditional result was False 2026-02-19 00:16:11.872453 | 2026-02-19 00:16:11.872574 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-19 00:16:11.896699 | controller | skipping: Conditional result was False 2026-02-19 00:16:11.908692 | 2026-02-19 00:16:11.908828 | TASK [Ensure python3.8 is present] 2026-02-19 00:16:11.942719 | controller | skipping: Conditional result was False 2026-02-19 00:16:11.950222 | 2026-02-19 00:16:11.950347 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-19 00:16:12.001392 | controller | ok 2026-02-19 00:16:12.050551 | 2026-02-19 00:16:12.050705 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-19 00:16:13.440867 | controller | ok: Nothing to do 2026-02-19 00:16:13.453839 | 2026-02-19 00:16:13.454162 | TASK [our-ensure-python : Also install python3-devel] 2026-02-19 00:16:22.638806 | controller | changed 2026-02-19 00:16:22.658278 | 2026-02-19 00:16:22.658427 | TASK [Run ensure-virtualenv role] 2026-02-19 00:16:22.685341 | controller | ok 2026-02-19 00:16:22.734006 | 2026-02-19 00:16:22.734198 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-19 00:16:23.045582 | controller | /usr/bin/virtualenv 2026-02-19 00:16:23.281460 | controller | ok: Runtime: 0:00:00.005612 2026-02-19 00:16:23.287144 | 2026-02-19 00:16:23.287222 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-19 00:16:23.327180 | controller | skipping: Conditional result was False 2026-02-19 00:16:23.327424 | controller | ok: All items complete 2026-02-19 00:16:23.327454 | 2026-02-19 00:16:23.351587 | 2026-02-19 00:16:23.351718 | TASK [Find the full path of the Python interpreter] 2026-02-19 00:16:23.565294 | controller | /usr/bin/python3 2026-02-19 00:16:23.896614 | controller | ok 2026-02-19 00:16:23.911332 | 2026-02-19 00:16:23.911549 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-19 00:16:24.723796 | controller | created virtual environment CPython3.11.0.final.0-64 in 467ms 2026-02-19 00:16:24.740432 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-19 00:16:24.740470 | 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-19 00:16:24.740478 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-19 00:16:24.740492 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-19 00:16:24.970150 | controller | changed 2026-02-19 00:16:24.977049 | 2026-02-19 00:16:24.977152 | TASK [Set selinux package] 2026-02-19 00:16:25.007999 | controller | ok 2026-02-19 00:16:25.014189 | 2026-02-19 00:16:25.014322 | TASK [Set selinux package (Fedora)] 2026-02-19 00:16:25.058523 | controller | ok 2026-02-19 00:16:25.069983 | 2026-02-19 00:16:25.070121 | TASK [Install selinux into virtualenv] 2026-02-19 00:16:50.563167 | controller | Collecting selinux-please-lie-to-me 2026-02-19 00:17:02.895819 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-19 00:17:03.204765 | controller | Collecting setuptools<50.0.0 2026-02-19 00:17:03.210854 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-19 00:17:03.255934 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.3 MB/s eta 0:00:00 2026-02-19 00:17:03.339061 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-19 00:17:03.339274 | controller | Attempting uninstall: setuptools 2026-02-19 00:17:03.341659 | controller | Found existing installation: setuptools 62.6.0 2026-02-19 00:17:03.403116 | controller | Uninstalling setuptools-62.6.0: 2026-02-19 00:17:03.412888 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-19 00:17:03.790824 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-19 00:17:15.366776 | controller | 2026-02-19 00:17:15.454610 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-19 00:17:15.454660 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-19 00:17:15.642462 | controller | ok: Runtime: 0:00:50.180984 2026-02-19 00:17:15.660000 | 2026-02-19 00:17:15.660174 | TASK [Install pytest-forked into virtualenv] 2026-02-19 00:17:27.509814 | controller | Collecting pytest-forked 2026-02-19 00:17:37.708011 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-19 00:17:37.748795 | controller | Collecting py 2026-02-19 00:17:37.753232 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-19 00:17:37.773926 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.6 MB/s eta 0:00:00 2026-02-19 00:17:37.879828 | controller | Collecting pytest>=3.10 2026-02-19 00:17:37.883287 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-19 00:17:37.898469 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.2 MB/s eta 0:00:00 2026-02-19 00:17:37.927489 | controller | Collecting iniconfig>=1.0.1 2026-02-19 00:17:37.931105 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-19 00:17:37.973288 | controller | Collecting packaging>=22 2026-02-19 00:17:37.976393 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-19 00:17:37.982714 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 17.4 MB/s eta 0:00:00 2026-02-19 00:17:38.016812 | controller | Collecting pluggy<2,>=1.5 2026-02-19 00:17:38.019807 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-19 00:17:38.065310 | controller | Collecting pygments>=2.7.2 2026-02-19 00:17:38.068517 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-19 00:17:38.094842 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.4 MB/s eta 0:00:00 2026-02-19 00:17:38.165567 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-19 00:17:39.191408 | 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-19 00:17:39.199790 | controller | 2026-02-19 00:17:39.267140 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-19 00:17:39.267176 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-19 00:17:39.722579 | controller | ok: Runtime: 0:00:23.384159 2026-02-19 00:17:39.731823 | 2026-02-19 00:17:39.731942 | TASK [Update pip] 2026-02-19 00:17:40.255711 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-19 00:17:52.715365 | controller | Collecting pip 2026-02-19 00:18:05.036082 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-19 00:18:05.095660 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 32.9 MB/s eta 0:00:00 2026-02-19 00:18:05.161176 | controller | Installing collected packages: pip 2026-02-19 00:18:05.161431 | controller | Attempting uninstall: pip 2026-02-19 00:18:05.163782 | controller | Found existing installation: pip 22.2.2 2026-02-19 00:18:05.312052 | controller | Uninstalling pip-22.2.2: 2026-02-19 00:18:05.327574 | controller | Successfully uninstalled pip-22.2.2 2026-02-19 00:18:06.184606 | controller | Successfully installed pip-26.0.1 2026-02-19 00:18:06.302482 | controller | ok: Runtime: 0:00:26.302626 2026-02-19 00:18:06.309050 | 2026-02-19 00:18:06.309176 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-19 00:18:06.524006 | controller | changed 2026-02-19 00:18:06.537818 | 2026-02-19 00:18:06.538011 | TASK [Install ansible into virtualenv] 2026-02-19 00:18:07.054517 | controller | Processing ./src/github.com/ansible/ansible 2026-02-19 00:18:07.057769 | controller | Installing build dependencies: started 2026-02-19 00:18:32.295146 | controller | Installing build dependencies: finished with status 'done' 2026-02-19 00:18:32.296293 | controller | Getting requirements to build wheel: started 2026-02-19 00:18:33.064184 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-19 00:18:33.065070 | controller | Preparing metadata (pyproject.toml): started 2026-02-19 00:18:33.538452 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-19 00:18:33.543400 | 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-19 00:18:33.549563 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-19 00:18:34.104684 | controller | ERROR 2026-02-19 00:18:34.104944 | controller | { 2026-02-19 00:18:34.104989 | controller | "delta": "0:00:26.837771", 2026-02-19 00:18:34.105023 | controller | "end": "2026-02-19 00:18:33.609372", 2026-02-19 00:18:34.105059 | controller | "msg": "non-zero return code", 2026-02-19 00:18:34.105099 | controller | "rc": 1, 2026-02-19 00:18:34.105126 | controller | "start": "2026-02-19 00:18:06.771601" 2026-02-19 00:18:34.105151 | controller | } failure 2026-02-19 00:18:34.106978 | 2026-02-19 00:18:34.107037 | PLAY RECAP 2026-02-19 00:18:34.107078 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-19 00:18:34.107110 | 2026-02-19 00:18:34.231478 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-19 00:18:34.232952 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-19 00:18:34.888650 | 2026-02-19 00:18:34.888823 | PLAY [all] 2026-02-19 00:18:34.916332 | 2026-02-19 00:18:34.916492 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-19 00:18:35.377223 | controller | changed: non-zero return code 2026-02-19 00:18:35.392246 | 2026-02-19 00:18:35.392658 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-19 00:18:35.411168 | controller | skipping: Conditional result was False 2026-02-19 00:18:35.423997 | 2026-02-19 00:18:35.424159 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-19 00:18:35.461294 | 2026-02-19 00:18:35.461501 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-19 00:18:35.495576 | 2026-02-19 00:18:35.495801 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-19 00:18:35.532480 | controller | skipping: Conditional result was False 2026-02-19 00:18:35.543698 | 2026-02-19 00:18:35.543862 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-19 00:18:35.589307 | 2026-02-19 00:18:35.589524 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-19 00:18:35.605700 | controller | skipping: Conditional result was False 2026-02-19 00:18:35.615681 | 2026-02-19 00:18:35.615842 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-19 00:18:35.631517 | controller | skipping: Conditional result was False 2026-02-19 00:18:35.640802 | 2026-02-19 00:18:35.640917 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-19 00:18:35.656187 | controller | skipping: Conditional result was False 2026-02-19 00:18:35.687544 | 2026-02-19 00:18:35.687650 | PLAY RECAP 2026-02-19 00:18:35.687691 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-19 00:18:35.687713 | 2026-02-19 00:18:35.843308 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-19 00:18:35.844186 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-19 00:18:36.469701 | 2026-02-19 00:18:36.469941 | PLAY [all:!appliance*] 2026-02-19 00:18:36.503956 | 2026-02-19 00:18:36.504101 | TASK [unregister the node] 2026-02-19 00:18:37.045422 | controller | skipping: Conditional result was False 2026-02-19 00:18:37.059173 | 2026-02-19 00:18:37.059365 | TASK [include_role : fetch-output] 2026-02-19 00:18:37.092475 | controller | ok 2026-02-19 00:18:37.134023 | 2026-02-19 00:18:37.134153 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-19 00:18:37.179383 | controller | skipping: Conditional result was False 2026-02-19 00:18:37.186345 | 2026-02-19 00:18:37.186429 | TASK [fetch-output : Set log path for single node] 2026-02-19 00:18:37.218410 | controller | ok 2026-02-19 00:18:37.224243 | 2026-02-19 00:18:37.224321 | LOOP [fetch-output : Ensure local output dirs] 2026-02-19 00:18:37.682917 | controller -> localhost | ok: "/var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/logs" 2026-02-19 00:18:37.978934 | controller -> localhost | changed: "/var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/artifacts" 2026-02-19 00:18:38.222248 | controller -> localhost | changed: "/var/lib/zuul/builds/39a624b08703485c8b222a29609829bf/work/docs" 2026-02-19 00:18:38.243382 | 2026-02-19 00:18:38.243521 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-19 00:18:38.927471 | controller | changed: 2026-02-19 00:18:38.928552 | controller | .d..t...... ./ 2026-02-19 00:18:38.928642 | controller | cd+++++++++ controller/ 2026-02-19 00:18:38.928758 | controller | changed: All items complete 2026-02-19 00:18:38.928821 | 2026-02-19 00:18:39.400342 | controller | changed: .d..t...... ./ 2026-02-19 00:18:39.894852 | controller | changed: .d..t...... ./ 2026-02-19 00:18:39.931502 | 2026-02-19 00:18:39.931654 | TASK [include_role : fetch-output-openshift] 2026-02-19 00:18:39.957494 | controller | skipping: Conditional result was False 2026-02-19 00:18:39.967955 | 2026-02-19 00:18:39.968081 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-19 00:18:40.016497 | controller | skipping: Conditional result was False 2026-02-19 00:18:40.030693 | controller | skipping: Conditional result was False 2026-02-19 00:18:40.077336 | 2026-02-19 00:18:40.077459 | PLAY [localhost] 2026-02-19 00:18:40.090943 | 2026-02-19 00:18:40.091048 | TASK [Run Zuul manifest role] 2026-02-19 00:18:40.110515 | localhost | ok 2026-02-19 00:18:40.130732 | 2026-02-19 00:18:40.130889 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-19 00:18:40.558774 | localhost | changed 2026-02-19 00:18:40.564211 | 2026-02-19 00:18:40.564306 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-19 00:18:40.592875 | localhost | ok 2026-02-19 00:18:40.601685 | 2026-02-19 00:18:40.601827 | TASK [Set zuul-log-path fact] 2026-02-19 00:18:40.620666 | localhost | ok 2026-02-19 00:18:40.636422 | 2026-02-19 00:18:40.636550 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-19 00:18:40.677441 | localhost | ok 2026-02-19 00:18:40.686083 | 2026-02-19 00:18:40.686187 | LOOP [Run upload-logs-swift role] 2026-02-19 00:18:40.735423 | localhost | Output suppressed because no_log was given 2026-02-19 00:18:40.772276 | 2026-02-19 00:18:40.772399 | TASK [Set zuul-log-path fact] 2026-02-19 00:18:40.817038 | localhost | skipping: Conditional result was False 2026-02-19 00:18:40.824305 | 2026-02-19 00:18:40.824586 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-19 00:18:41.238584 | localhost -> localhost | ok: Runtime: 0:00:00.009088 2026-02-19 00:18:41.245438 | 2026-02-19 00:18:41.245567 | TASK [upload-logs-swift : Upload logs to swift]