2025-10-11 00:13:57.450590 | Job console starting... 2025-10-11 00:13:57.460431 | Updating repositories 2025-10-11 00:13:57.566278 | Preparing job workspace 2025-10-11 00:14:02.505377 | Running Ansible setup... 2025-10-11 00:14:10.439171 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-10-11 00:14:11.096526 | 2025-10-11 00:14:11.096689 | PLAY [localhost] 2025-10-11 00:14:11.108508 | 2025-10-11 00:14:11.108661 | TASK [Gathering Facts] 2025-10-11 00:14:12.132567 | localhost | ok 2025-10-11 00:14:12.166808 | 2025-10-11 00:14:12.166993 | TASK [Setup log path fact] 2025-10-11 00:14:12.187088 | localhost | ok 2025-10-11 00:14:12.202262 | 2025-10-11 00:14:12.202385 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-11 00:14:12.231248 | localhost | ok 2025-10-11 00:14:12.241396 | 2025-10-11 00:14:12.241515 | TASK [emit-job-header : Print job information] 2025-10-11 00:14:12.281278 | # Job Information 2025-10-11 00:14:12.281441 | Ansible Version: 2.15.12 2025-10-11 00:14:12.281473 | Job: ansible-test-sanity-docker-stable-2.9 2025-10-11 00:14:12.281496 | Pipeline: periodic 2025-10-11 00:14:12.281516 | Executor: ze01.softwarefactory-project.io 2025-10-11 00:14:12.281536 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-10-11 00:14:12.281558 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/d39/ansible/d395a2f5675d4f02af5110fed118694f/ 2025-10-11 00:14:12.281579 | Event ID: d6ccd92d500144d2bcd347dd8f427b4a 2025-10-11 00:14:12.285972 | 2025-10-11 00:14:12.286095 | LOOP [emit-job-header : Print node information] 2025-10-11 00:14:12.409710 | localhost | ok: 2025-10-11 00:14:12.409929 | localhost | # Node Information 2025-10-11 00:14:12.409956 | localhost | Inventory Hostname: controller 2025-10-11 00:14:12.409975 | localhost | Hostname: np0005480787 2025-10-11 00:14:12.409994 | localhost | Username: zuul 2025-10-11 00:14:12.410040 | localhost | Distro: Fedora 37 2025-10-11 00:14:12.410064 | localhost | Provider: ansible-vexxhost-ams1 2025-10-11 00:14:12.410083 | localhost | Region: ams1 2025-10-11 00:14:12.410115 | localhost | Label: ansible-fedora-37-1vcpu 2025-10-11 00:14:12.410133 | localhost | Product Name: OpenStack Nova 2025-10-11 00:14:12.410151 | localhost | Interface IP: 38.129.16.108 2025-10-11 00:14:12.424835 | 2025-10-11 00:14:12.424984 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-11 00:14:12.842090 | localhost -> localhost | changed 2025-10-11 00:14:12.851649 | 2025-10-11 00:14:12.851790 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-11 00:14:13.747000 | localhost -> localhost | changed 2025-10-11 00:14:13.772195 | 2025-10-11 00:14:13.772290 | PLAY [all:!appliance*] 2025-10-11 00:14:13.793357 | 2025-10-11 00:14:13.793497 | TASK [include_role : start-zuul-console] 2025-10-11 00:14:13.818345 | controller | ok 2025-10-11 00:14:13.844213 | 2025-10-11 00:14:13.844406 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-11 00:14:14.979416 | controller | ok 2025-10-11 00:14:14.996527 | 2025-10-11 00:14:14.996665 | TASK [use-our-mirror : Retrieve the IP address] 2025-10-11 00:14:17.393165 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-10-11 00:14:17.408135 | 2025-10-11 00:14:17.408270 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-10-11 00:14:17.777580 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.785201 | 2025-10-11 00:14:17.785315 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-10-11 00:14:17.809456 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.819467 | 2025-10-11 00:14:17.819605 | TASK [use-our-mirror : Create the podman configuration directory] 2025-10-11 00:14:17.835424 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.845956 | 2025-10-11 00:14:17.846114 | TASK [use-our-mirror : Copy the podman configuration] 2025-10-11 00:14:17.869900 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.876974 | 2025-10-11 00:14:17.877099 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-10-11 00:14:17.906584 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.913153 | 2025-10-11 00:14:17.913271 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-10-11 00:14:17.936973 | controller | skipping: Conditional result was False 2025-10-11 00:14:17.952772 | 2025-10-11 00:14:17.952906 | TASK [Disable Fedora Modular] 2025-10-11 00:14:19.123669 | controller | changed 2025-10-11 00:14:19.136898 | 2025-10-11 00:14:19.137045 | TASK [Enable EPEL] 2025-10-11 00:14:19.161303 | controller | skipping: Conditional result was False 2025-10-11 00:14:19.169548 | 2025-10-11 00:14:19.169695 | TASK [Register the RHEL node] 2025-10-11 00:14:19.587228 | 2025-10-11 00:14:19.587532 | TASK [Show the subscription-manager status] 2025-10-11 00:14:19.970140 | controller | skipping: Conditional result was False 2025-10-11 00:14:19.977302 | 2025-10-11 00:14:19.977643 | TASK [Enable EPEL on RHEL] 2025-10-11 00:14:20.399285 | controller | skipping: Conditional result was False 2025-10-11 00:14:20.407443 | 2025-10-11 00:14:20.407586 | TASK [Install git and tox] 2025-10-11 00:17:12.918555 | controller | changed 2025-10-11 00:17:12.924686 | 2025-10-11 00:17:12.924751 | TASK [include_role : prepare-workspace] 2025-10-11 00:17:12.952421 | controller | ok 2025-10-11 00:17:12.987378 | 2025-10-11 00:17:12.987519 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-11 00:17:13.861832 | controller | ok 2025-10-11 00:17:13.872215 | 2025-10-11 00:17:13.872352 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-11 00:17:36.779072 | controller | Output suppressed because no_log was given 2025-10-11 00:17:36.794377 | 2025-10-11 00:17:36.794515 | TASK [include_role : prepare-workspace-openshift] 2025-10-11 00:17:36.817186 | controller | skipping: Conditional result was False 2025-10-11 00:17:36.842572 | 2025-10-11 00:17:36.842676 | PLAY [all:!appliance] 2025-10-11 00:17:36.860592 | 2025-10-11 00:17:36.860713 | TASK [Run add-build-sshkey role (RSA)] 2025-10-11 00:17:36.892459 | controller | ok 2025-10-11 00:17:36.909974 | 2025-10-11 00:17:36.910118 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-11 00:17:37.185291 | controller -> localhost | ok 2025-10-11 00:17:37.192272 | 2025-10-11 00:17:37.192373 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-11 00:17:37.233298 | controller | ok 2025-10-11 00:17:37.248938 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-11 00:17:37.256819 | 2025-10-11 00:17:37.256956 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-11 00:17:37.731273 | controller -> localhost | Generating public/private rsa key pair. 2025-10-11 00:17:37.731714 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_rsa. 2025-10-11 00:17:37.731751 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_rsa.pub. 2025-10-11 00:17:37.731779 | controller -> localhost | The key fingerprint is: 2025-10-11 00:17:37.731806 | controller -> localhost | SHA256:d1Z7V0pcj91f+WEo7UaSNwo807zcCKXvfFOGoSvBb38 zuul-build-sshkey 2025-10-11 00:17:37.731830 | controller -> localhost | The key's randomart image is: 2025-10-11 00:17:37.731856 | controller -> localhost | +---[RSA 2048]----+ 2025-10-11 00:17:37.731881 | controller -> localhost | | . .| 2025-10-11 00:17:37.731905 | controller -> localhost | | . = o..++| 2025-10-11 00:17:37.731929 | controller -> localhost | | B * B=+*| 2025-10-11 00:17:37.731952 | controller -> localhost | | . B %o=o*| 2025-10-11 00:17:37.731975 | controller -> localhost | | So.Bo=oo=| 2025-10-11 00:17:37.732010 | controller -> localhost | | .=oo o..| 2025-10-11 00:17:37.732065 | controller -> localhost | | . * o | 2025-10-11 00:17:37.732091 | controller -> localhost | | o o .E | 2025-10-11 00:17:37.732116 | controller -> localhost | | .. | 2025-10-11 00:17:37.732143 | controller -> localhost | +----[SHA256]-----+ 2025-10-11 00:17:37.732201 | controller -> localhost | ok: Runtime: 0:00:00.050413 2025-10-11 00:17:37.741813 | 2025-10-11 00:17:37.741933 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-11 00:17:37.774592 | controller | ok 2025-10-11 00:17:37.785133 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-11 00:17:37.794751 | 2025-10-11 00:17:37.794885 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-11 00:17:37.819623 | controller | skipping: Conditional result was False 2025-10-11 00:17:37.825884 | 2025-10-11 00:17:37.825995 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-11 00:17:38.960783 | controller | changed 2025-10-11 00:17:38.975203 | 2025-10-11 00:17:38.975545 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-11 00:17:39.680285 | controller | ok 2025-10-11 00:17:39.696211 | 2025-10-11 00:17:39.696408 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-11 00:17:42.772217 | controller | changed 2025-10-11 00:17:42.785865 | 2025-10-11 00:17:42.786058 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-11 00:17:45.897721 | controller | changed 2025-10-11 00:17:45.904244 | 2025-10-11 00:17:45.904406 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-11 00:17:45.928929 | controller | skipping: Conditional result was False 2025-10-11 00:17:45.938289 | 2025-10-11 00:17:45.938441 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-11 00:17:46.340995 | controller -> localhost | changed 2025-10-11 00:17:46.362300 | 2025-10-11 00:17:46.362432 | TASK [add-build-sshkey : Add back temp key] 2025-10-11 00:17:46.694370 | controller -> localhost | Identity added: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_rsa (zuul-build-sshkey) 2025-10-11 00:17:46.694581 | controller -> localhost | ok: Runtime: 0:00:00.009584 2025-10-11 00:17:46.701006 | 2025-10-11 00:17:46.701096 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-11 00:17:47.686413 | controller | ok 2025-10-11 00:17:47.702985 | 2025-10-11 00:17:47.703238 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-11 00:17:47.744520 | controller | skipping: Conditional result was False 2025-10-11 00:17:47.770904 | 2025-10-11 00:17:47.771310 | TASK [Run add-build-sshkey role (ECDSA)] 2025-10-11 00:17:47.803965 | controller | ok 2025-10-11 00:17:47.840413 | 2025-10-11 00:17:47.840554 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-11 00:17:48.159352 | controller -> localhost | ok 2025-10-11 00:17:48.169857 | 2025-10-11 00:17:48.170057 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-11 00:17:48.203884 | controller | ok 2025-10-11 00:17:48.219680 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-11 00:17:48.228775 | 2025-10-11 00:17:48.228911 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-11 00:17:48.565919 | controller -> localhost | Generating public/private ecdsa key pair. 2025-10-11 00:17:48.566109 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_ecdsa. 2025-10-11 00:17:48.566138 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_ecdsa.pub. 2025-10-11 00:17:48.566169 | controller -> localhost | The key fingerprint is: 2025-10-11 00:17:48.566212 | controller -> localhost | SHA256:WAmORNxjnvNjsGOfI2Qev30sainbOEY6C/yxHbms78Q zuul-build-sshkey 2025-10-11 00:17:48.566247 | controller -> localhost | The key's randomart image is: 2025-10-11 00:17:48.566270 | controller -> localhost | +---[ECDSA 521]---+ 2025-10-11 00:17:48.566290 | controller -> localhost | | oo.. | 2025-10-11 00:17:48.566309 | controller -> localhost | | ..o+. . | 2025-10-11 00:17:48.566327 | controller -> localhost | | .o.oo | 2025-10-11 00:17:48.566345 | controller -> localhost | | =o | 2025-10-11 00:17:48.566363 | controller -> localhost | | .=S | 2025-10-11 00:17:48.566382 | controller -> localhost | | . .O.+ | 2025-10-11 00:17:48.566399 | controller -> localhost | | o .BE* + . | 2025-10-11 00:17:48.566424 | controller -> localhost | | oo**=B.. o | 2025-10-11 00:17:48.566453 | controller -> localhost | | =BO*++.o | 2025-10-11 00:17:48.566481 | controller -> localhost | +----[SHA256]-----+ 2025-10-11 00:17:48.566536 | controller -> localhost | ok: Runtime: 0:00:00.015902 2025-10-11 00:17:48.574622 | 2025-10-11 00:17:48.574716 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-11 00:17:48.607089 | controller | ok 2025-10-11 00:17:48.619565 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-11 00:17:48.630802 | 2025-10-11 00:17:48.630907 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-11 00:17:48.645733 | controller | skipping: Conditional result was False 2025-10-11 00:17:48.655660 | 2025-10-11 00:17:48.655792 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-11 00:17:49.609192 | controller | changed 2025-10-11 00:17:49.617085 | 2025-10-11 00:17:49.617153 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-11 00:17:50.292850 | controller | ok 2025-10-11 00:17:50.301929 | 2025-10-11 00:17:50.302041 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-11 00:17:53.367147 | controller | changed 2025-10-11 00:17:53.375596 | 2025-10-11 00:17:53.375688 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-11 00:17:56.416485 | controller | changed 2025-10-11 00:17:56.425417 | 2025-10-11 00:17:56.425507 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-11 00:17:56.441147 | controller | skipping: Conditional result was False 2025-10-11 00:17:56.452864 | 2025-10-11 00:17:56.453061 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-11 00:17:56.682355 | controller -> localhost | changed 2025-10-11 00:17:56.700610 | 2025-10-11 00:17:56.700744 | TASK [add-build-sshkey : Add back temp key] 2025-10-11 00:17:56.971362 | controller -> localhost | Identity added: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/d395a2f5675d4f02af5110fed118694f_id_ecdsa (zuul-build-sshkey) 2025-10-11 00:17:56.971640 | controller -> localhost | ok: Runtime: 0:00:00.007761 2025-10-11 00:17:56.978994 | 2025-10-11 00:17:56.979092 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-11 00:17:57.713719 | controller | ok 2025-10-11 00:17:57.727441 | 2025-10-11 00:17:57.727649 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-11 00:17:57.768109 | controller | skipping: Conditional result was False 2025-10-11 00:17:57.794106 | 2025-10-11 00:17:57.794248 | TASK [include_role : remove-zuul-sshkey] 2025-10-11 00:17:57.822713 | controller | skipping: Conditional result was False 2025-10-11 00:17:57.831792 | 2025-10-11 00:17:57.831883 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-11 00:17:58.526085 | controller | ok: "logs" 2025-10-11 00:17:58.526331 | controller | ok: All items complete 2025-10-11 00:17:58.526358 | 2025-10-11 00:17:59.219733 | controller | ok: "artifacts" 2025-10-11 00:17:59.895220 | controller | ok: "docs" 2025-10-11 00:17:59.909752 | 2025-10-11 00:17:59.909996 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-11 00:18:00.585977 | controller | changed: "logs" 2025-10-11 00:18:01.227554 | controller | changed: "artifacts" 2025-10-11 00:18:01.866465 | controller | changed: "docs" 2025-10-11 00:18:01.979370 | 2025-10-11 00:18:01.979493 | PLAY RECAP 2025-10-11 00:18:01.979549 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-10-11 00:18:01.979583 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-11 00:18:01.979602 | 2025-10-11 00:18:02.129056 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-10-11 00:18:02.130749 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-11 00:18:02.745194 | 2025-10-11 00:18:02.745335 | PLAY [all] 2025-10-11 00:18:02.768093 | 2025-10-11 00:18:02.768211 | TASK [Install binary dependencies] 2025-10-11 00:18:02.841900 | controller | ok 2025-10-11 00:18:02.865072 | 2025-10-11 00:18:02.865198 | TASK [bindep : Include find tasks] 2025-10-11 00:18:02.894409 | controller | ok 2025-10-11 00:18:02.901995 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-11 00:18:02.909451 | 2025-10-11 00:18:02.909574 | TASK [bindep : Look for bindep.txt] 2025-10-11 00:18:03.892735 | controller | ok 2025-10-11 00:18:03.906756 | 2025-10-11 00:18:03.907137 | TASK [bindep : Define bindep_file fact] 2025-10-11 00:18:03.935604 | controller | skipping: Conditional result was False 2025-10-11 00:18:03.949970 | 2025-10-11 00:18:03.950174 | TASK [bindep : Look for other-requirements.txt] 2025-10-11 00:18:04.627558 | controller | ok 2025-10-11 00:18:04.636599 | 2025-10-11 00:18:04.636709 | TASK [bindep : Define bindep_file fact] 2025-10-11 00:18:04.673679 | controller | skipping: Conditional result was False 2025-10-11 00:18:04.686995 | 2025-10-11 00:18:04.687223 | TASK [bindep : Look for bindep fallback file] 2025-10-11 00:18:04.736844 | controller | skipping: Conditional result was False 2025-10-11 00:18:04.750711 | 2025-10-11 00:18:04.750925 | TASK [bindep : Define bindep_file fact] 2025-10-11 00:18:04.778670 | controller | skipping: Conditional result was False 2025-10-11 00:18:04.794439 | 2025-10-11 00:18:04.794631 | TASK [bindep : Include bindep tasks] 2025-10-11 00:18:04.822104 | controller | skipping: Conditional result was False 2025-10-11 00:18:04.836291 | 2025-10-11 00:18:04.836485 | TASK [bindep : Include install tasks] 2025-10-11 00:18:04.862760 | controller | skipping: Conditional result was False 2025-10-11 00:18:04.872286 | 2025-10-11 00:18:04.872428 | LOOP [bindep : Include package tasks] 2025-10-11 00:18:04.956447 | 2025-10-11 00:18:04.956679 | TASK [Run test-setup role] 2025-10-11 00:18:04.984702 | controller | ok 2025-10-11 00:18:05.014367 | 2025-10-11 00:18:05.014512 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-11 00:18:05.770976 | controller | ok 2025-10-11 00:18:05.784380 | 2025-10-11 00:18:05.784532 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-11 00:18:06.156152 | controller | skipping: Conditional result was False 2025-10-11 00:18:06.213854 | 2025-10-11 00:18:06.213968 | PLAY RECAP 2025-10-11 00:18:06.214048 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-11 00:18:06.214086 | 2025-10-11 00:18:06.334087 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-11 00:18:06.334969 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-10-11 00:18:07.001516 | 2025-10-11 00:18:07.001661 | PLAY [controller] 2025-10-11 00:18:07.024166 | 2025-10-11 00:18:07.024332 | TASK [Create the /root directory] 2025-10-11 00:18:08.208121 | controller | ok 2025-10-11 00:18:08.220233 | 2025-10-11 00:18:08.220375 | TASK [Install glibc-langpack-en] 2025-10-11 00:18:17.709509 | controller | ok: Nothing to do 2025-10-11 00:18:17.716143 | 2025-10-11 00:18:17.716238 | TASK [Ensure controller directory exists] 2025-10-11 00:18:18.579074 | controller | changed 2025-10-11 00:18:18.591784 | 2025-10-11 00:18:18.591932 | TASK [Install container runtime] 2025-10-11 00:18:18.654010 | controller | ok 2025-10-11 00:18:18.719641 | 2025-10-11 00:18:18.719757 | LOOP [ensure-docker : Gather variables for each operating system] 2025-10-11 00:18:18.771146 | controller | ok: "/var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml" 2025-10-11 00:18:18.786695 | 2025-10-11 00:18:18.786851 | TASK [ensure-docker : Sanity check for distro selection] 2025-10-11 00:18:18.812944 | controller | skipping: Conditional result was False 2025-10-11 00:18:18.822230 | 2025-10-11 00:18:18.822366 | TASK [ensure-docker : Sanity check for distro install] 2025-10-11 00:18:18.848093 | controller | skipping: Conditional result was False 2025-10-11 00:18:18.857488 | 2025-10-11 00:18:18.857641 | TASK [ensure-docker : Sanity check for upstream install] 2025-10-11 00:18:18.882986 | controller | skipping: Conditional result was False 2025-10-11 00:18:18.892393 | 2025-10-11 00:18:18.892523 | TASK [ensure-docker : Sanity check for upstream install mirrors] 2025-10-11 00:18:18.917547 | controller | skipping: Conditional result was False 2025-10-11 00:18:18.927105 | 2025-10-11 00:18:18.927230 | TASK [ensure-docker : Include tasks for docker install] 2025-10-11 00:18:18.952500 | controller | ok 2025-10-11 00:18:18.965636 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml 2025-10-11 00:18:18.978568 | 2025-10-11 00:18:18.978738 | TASK [ensure-docker : Not Implemented] 2025-10-11 00:18:18.994150 | controller | skipping: Conditional result was False 2025-10-11 00:18:19.001337 | 2025-10-11 00:18:19.001443 | TASK [Set up docker mirrors] 2025-10-11 00:18:19.020700 | controller | ok 2025-10-11 00:18:19.067545 | 2025-10-11 00:18:19.067663 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info] 2025-10-11 00:18:19.092002 | controller | skipping: Conditional result was False 2025-10-11 00:18:19.099132 | 2025-10-11 00:18:19.099224 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info] 2025-10-11 00:18:19.133783 | controller | skipping: Conditional result was False 2025-10-11 00:18:19.140415 | 2025-10-11 00:18:19.140519 | TASK [use-docker-mirror : Set docker_mirror fact] 2025-10-11 00:18:19.166194 | controller | skipping: Conditional result was False 2025-10-11 00:18:19.173925 | 2025-10-11 00:18:19.174051 | TASK [use-docker-mirror : Set up docker mirrors] 2025-10-11 00:18:19.198592 | controller | skipping: Conditional result was False 2025-10-11 00:18:19.210783 | 2025-10-11 00:18:19.210893 | TASK [Add all repositories] 2025-10-11 00:18:19.231945 | controller | ok 2025-10-11 00:18:19.256568 | 2025-10-11 00:18:19.256699 | LOOP [ensure-package-repositories : Install repositories] 2025-10-11 00:18:19.281967 | controller | ok: "/var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml" 2025-10-11 00:18:19.282362 | controller | ok: All items complete 2025-10-11 00:18:19.282406 | 2025-10-11 00:18:19.300904 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml 2025-10-11 00:18:19.307876 | 2025-10-11 00:18:19.307966 | TASK [ensure-package-repositories : Create GPG key temp directory] 2025-10-11 00:18:20.316647 | controller | changed 2025-10-11 00:18:20.333377 | 2025-10-11 00:18:20.333607 | LOOP [ensure-package-repositories : Upload GPG keys] 2025-10-11 00:18:23.706516 | controller | changed: 2025-10-11 00:18:23.706782 | controller | { 2025-10-11 00:18:23.706837 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2025-10-11 00:18:23.706880 | controller | } 2025-10-11 00:18:23.731263 | 2025-10-11 00:18:23.731435 | LOOP [ensure-package-repositories : Import GPG keys] 2025-10-11 00:18:25.187388 | controller | changed: 2025-10-11 00:18:25.187722 | controller | { 2025-10-11 00:18:25.187807 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2025-10-11 00:18:25.187873 | controller | } 2025-10-11 00:18:25.187957 | controller | changed: All items complete 2025-10-11 00:18:25.188076 | 2025-10-11 00:18:25.209254 | 2025-10-11 00:18:25.209513 | TASK [ensure-package-repositories : Remove GPG temp directory] 2025-10-11 00:18:26.027620 | controller | changed 2025-10-11 00:18:26.046362 | 2025-10-11 00:18:26.046544 | LOOP [ensure-package-repositories : Add repositories] 2025-10-11 00:18:26.959356 | controller | changed: 2025-10-11 00:18:26.959609 | controller | { 2025-10-11 00:18:26.959655 | controller | "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable", 2025-10-11 00:18:26.959690 | controller | "description": "Docker CE Stable - $basearch", 2025-10-11 00:18:26.959721 | controller | "gpgcheck": true, 2025-10-11 00:18:26.959752 | controller | "name": "docker-ce-stable" 2025-10-11 00:18:26.959783 | controller | } 2025-10-11 00:18:26.978937 | 2025-10-11 00:18:26.979089 | TASK [ensure-docker : Install pre-reqs] 2025-10-11 00:18:32.811374 | controller | ok: Nothing to do 2025-10-11 00:18:32.821223 | 2025-10-11 00:18:32.821466 | TASK [ensure-docker : Remove packages] 2025-10-11 00:18:36.587419 | controller | ok: Nothing to do 2025-10-11 00:18:36.601315 | 2025-10-11 00:18:36.601512 | TASK [ensure-docker : Install upstream docker using package] 2025-10-11 00:20:10.171947 | controller | changed 2025-10-11 00:20:10.178520 | 2025-10-11 00:20:10.178629 | TASK [ensure-docker : Setup docker] 2025-10-11 00:20:10.198935 | controller | ok 2025-10-11 00:20:10.212937 | controller | included: /var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml 2025-10-11 00:20:10.273331 | 2025-10-11 00:20:10.273445 | TASK [ensure-docker : Ensure "docker" group exists] 2025-10-11 00:20:11.315484 | controller | ok 2025-10-11 00:20:11.322864 | 2025-10-11 00:20:11.322991 | TASK [ensure-docker : Add user to docker group] 2025-10-11 00:20:12.402247 | controller | changed 2025-10-11 00:20:12.413412 | 2025-10-11 00:20:12.413590 | TASK [Update docker daemon proxy configuration] 2025-10-11 00:20:12.450645 | controller | skipping: Conditional result was False 2025-10-11 00:20:12.461443 | 2025-10-11 00:20:12.461566 | TASK [Lower default MTU] 2025-10-11 00:20:12.477970 | controller | skipping: Conditional result was False 2025-10-11 00:20:12.503275 | 2025-10-11 00:20:12.503435 | TASK [ensure-docker : Get the status of the docket.socket unit] 2025-10-11 00:20:13.306388 | controller | inactive 2025-10-11 00:20:13.875528 | controller | ok: Runtime: 0:00:00.024454 2025-10-11 00:20:13.883309 | 2025-10-11 00:20:13.883423 | TASK [ensure-docker : Get the status of the docket unit] 2025-10-11 00:20:14.616119 | controller | inactive 2025-10-11 00:20:14.744747 | controller | ok: Runtime: 0:00:00.018851 2025-10-11 00:20:14.755804 | 2025-10-11 00:20:14.755923 | TASK [ensure-docker : Restart docker] 2025-10-11 00:20:14.803532 | Trigger a Docker restart 2025-10-11 00:20:14.813147 | 2025-10-11 00:20:14.813349 | TASK [ensure-docker : Reset ssh connection to pick up docker group] 2025-10-11 00:20:14.847934 | 2025-10-11 00:20:14.848108 | TASK [ensure-docker : Install docker-compose] 2025-10-11 00:20:14.874320 | controller | skipping: Conditional result was False 2025-10-11 00:20:14.883176 | 2025-10-11 00:20:14.883341 | TASK [ensure-docker : Flush handlers before role exit] 2025-10-11 00:20:14.895546 | 2025-10-11 00:20:14.895679 | TASK [ensure-docker : Stop docker.socket to avoid any conflict] 2025-10-11 00:20:18.599086 | controller | changed 2025-10-11 00:20:18.609799 | 2025-10-11 00:20:18.609931 | TASK [ensure-docker : Assure docker service is running] 2025-10-11 00:20:22.353927 | controller | changed 2025-10-11 00:20:22.362719 | 2025-10-11 00:20:22.362844 | TASK [ensure-docker : Assure docker.socket service is running] 2025-10-11 00:20:24.193752 | controller | ok 2025-10-11 00:20:24.204780 | 2025-10-11 00:20:24.204912 | TASK [ensure-docker : Correct group ownership on docker sock] 2025-10-11 00:20:25.132111 | controller | ok 2025-10-11 00:20:25.138277 | 2025-10-11 00:20:25.138348 | TASK [ensure-docker : Validate ability to talk with docker] 2025-10-11 00:20:25.782950 | controller | CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 2025-10-11 00:20:25.996813 | controller | ok: Runtime: 0:00:00.045316 2025-10-11 00:20:26.010626 | 2025-10-11 00:20:26.010790 | TASK [ensure-docker : Get version details] 2025-10-11 00:20:26.719420 | controller | Client: Docker Engine - Community 2025-10-11 00:20:26.722350 | controller | Version: 24.0.7 2025-10-11 00:20:26.722409 | controller | API version: 1.43 2025-10-11 00:20:26.722422 | controller | Go version: go1.20.10 2025-10-11 00:20:26.722446 | controller | Git commit: afdd53b 2025-10-11 00:20:26.722457 | controller | Built: Thu Oct 26 09:09:39 2023 2025-10-11 00:20:26.722467 | controller | OS/Arch: linux/amd64 2025-10-11 00:20:26.722479 | controller | Context: default 2025-10-11 00:20:26.722491 | controller | 2025-10-11 00:20:26.722501 | controller | Server: Docker Engine - Community 2025-10-11 00:20:26.722510 | controller | Engine: 2025-10-11 00:20:26.722519 | controller | Version: 24.0.7 2025-10-11 00:20:26.722528 | controller | API version: 1.43 (minimum version 1.12) 2025-10-11 00:20:26.722536 | controller | Go version: go1.20.10 2025-10-11 00:20:26.722545 | controller | Git commit: 311b9ff 2025-10-11 00:20:26.722555 | controller | Built: Thu Oct 26 09:08:11 2023 2025-10-11 00:20:26.722564 | controller | OS/Arch: linux/amd64 2025-10-11 00:20:26.722573 | controller | Experimental: false 2025-10-11 00:20:26.722582 | controller | containerd: 2025-10-11 00:20:26.722590 | controller | Version: 1.6.25 2025-10-11 00:20:26.722599 | controller | GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f 2025-10-11 00:20:26.722608 | controller | runc: 2025-10-11 00:20:26.722617 | controller | Version: 1.1.10 2025-10-11 00:20:26.722626 | controller | GitCommit: v1.1.10-0-g18a0cb0 2025-10-11 00:20:26.722637 | controller | docker-init: 2025-10-11 00:20:26.722646 | controller | Version: 0.19.0 2025-10-11 00:20:26.722655 | controller | GitCommit: de40ad0 2025-10-11 00:20:26.923592 | controller | ok: Runtime: 0:00:00.054958 2025-10-11 00:20:26.933637 | 2025-10-11 00:20:26.933754 | TASK [ensure-docker : Dump installed docker details] 2025-10-11 00:20:26.977960 | {'changed': True, 'stdout': 'Client: Docker Engine - Community\n Version: 24.0.7\n API version: 1.43\n Go version: go1.20.10\n Git commit: afdd53b\n Built: Thu Oct 26 09:09:39 2023\n OS/Arch: linux/amd64\n Context: default\n\nServer: Docker Engine - Community\n Engine:\n Version: 24.0.7\n API version: 1.43 (minimum version 1.12)\n Go version: go1.20.10\n Git commit: 311b9ff\n Built: Thu Oct 26 09:08:11 2023\n OS/Arch: linux/amd64\n Experimental: false\n containerd:\n Version: 1.6.25\n GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f\n runc:\n Version: 1.1.10\n GitCommit: v1.1.10-0-g18a0cb0\n docker-init:\n Version: 0.19.0\n GitCommit: de40ad0', 'stderr': '', 'rc': 0, 'cmd': ['docker', 'version'], 'start': '2025-10-11 00:20:26.668049', 'end': '2025-10-11 00:20:26.723007', 'delta': '0:00:00.054958', 'msg': '', 'zuul_log_id': 'fa163ec2-ffbe-7b7f-fe67-000000000061-1-controller', 'stdout_lines': ['Client: Docker Engine - Community', ' Version: 24.0.7', ' API version: 1.43', ' Go version: go1.20.10', ' Git commit: afdd53b', ' Built: Thu Oct 26 09:09:39 2023', ' OS/Arch: linux/amd64', ' Context: default', '', 'Server: Docker Engine - Community', ' Engine:', ' Version: 24.0.7', ' API version: 1.43 (minimum version 1.12)', ' Go version: go1.20.10', ' Git commit: 311b9ff', ' Built: Thu Oct 26 09:08:11 2023', ' OS/Arch: linux/amd64', ' Experimental: false', ' containerd:', ' Version: 1.6.25', ' GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f', ' runc:', ' Version: 1.1.10', ' GitCommit: v1.1.10-0-g18a0cb0', ' docker-init:', ' Version: 0.19.0', ' GitCommit: de40ad0'], 'stderr_lines': [], 'failed': False} 2025-10-11 00:20:26.987563 | 2025-10-11 00:20:26.987701 | TASK [Use buildset registry] 2025-10-11 00:20:27.013878 | controller | skipping: Conditional result was False 2025-10-11 00:20:27.033382 | 2025-10-11 00:20:27.033531 | TASK [Ensure python3.8 is present] 2025-10-11 00:20:27.049531 | controller | skipping: Conditional result was False 2025-10-11 00:20:27.058583 | 2025-10-11 00:20:27.058706 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-10-11 00:20:27.081601 | controller | ok 2025-10-11 00:20:27.107978 | 2025-10-11 00:20:27.108134 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-10-11 00:20:32.865423 | controller | ok: Nothing to do 2025-10-11 00:20:32.871846 | 2025-10-11 00:20:32.871940 | TASK [our-ensure-python : Also install python3-devel] 2025-10-11 00:20:51.890342 | controller | changed 2025-10-11 00:20:51.901820 | 2025-10-11 00:20:51.901948 | TASK [Run ensure-virtualenv role] 2025-10-11 00:20:51.922962 | controller | ok 2025-10-11 00:20:51.947064 | 2025-10-11 00:20:51.947185 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-10-11 00:20:52.709151 | controller | /usr/bin/virtualenv 2025-10-11 00:20:53.304610 | controller | ok: Runtime: 0:00:00.007981 2025-10-11 00:20:53.312850 | 2025-10-11 00:20:53.313151 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-10-11 00:20:53.352377 | controller | skipping: Conditional result was False 2025-10-11 00:20:53.352688 | controller | changed: All items complete 2025-10-11 00:20:53.352727 | 2025-10-11 00:20:53.370847 | 2025-10-11 00:20:53.370972 | TASK [Find the full path of the Python interpreter] 2025-10-11 00:20:54.214449 | controller | /usr/bin/python3.8 2025-10-11 00:20:54.747331 | controller | ok 2025-10-11 00:20:54.753285 | 2025-10-11 00:20:54.753385 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-10-11 00:20:57.176880 | controller | created virtual environment CPython3.8.18.final.0-64 in 1357ms 2025-10-11 00:20:57.305437 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-10-11 00:20:57.305496 | 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-10-11 00:20:57.305511 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-10-11 00:20:57.305532 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-10-11 00:20:57.618758 | controller | changed 2025-10-11 00:20:57.628259 | 2025-10-11 00:20:57.628414 | TASK [Set selinux package] 2025-10-11 00:20:57.649939 | controller | ok 2025-10-11 00:20:57.655191 | 2025-10-11 00:20:57.655427 | TASK [Set selinux package (Fedora)] 2025-10-11 00:20:57.686351 | controller | ok 2025-10-11 00:20:57.725394 | 2025-10-11 00:20:57.725514 | TASK [Install selinux into virtualenv] 2025-10-11 00:21:04.996549 | controller | Collecting selinux-please-lie-to-me 2025-10-11 00:21:05.080140 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-10-11 00:21:05.845970 | controller | Collecting setuptools<50.0.0 2025-10-11 00:21:05.856452 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-10-11 00:21:05.927799 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 12.7 MB/s eta 0:00:00 2025-10-11 00:21:06.114359 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-10-11 00:21:06.114668 | controller | Attempting uninstall: setuptools 2025-10-11 00:21:06.116132 | controller | Found existing installation: setuptools 62.6.0 2025-10-11 00:21:06.277455 | controller | Uninstalling setuptools-62.6.0: 2025-10-11 00:21:06.307450 | controller | Successfully uninstalled setuptools-62.6.0 2025-10-11 00:21:07.539278 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-10-11 00:21:07.800451 | controller | 2025-10-11 00:21:08.052936 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1 2025-10-11 00:21:08.052992 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-10-11 00:21:08.617960 | controller | ok: Runtime: 0:00:09.209584 2025-10-11 00:21:08.626214 | 2025-10-11 00:21:08.626327 | TASK [Install pytest-forked into virtualenv] 2025-10-11 00:21:10.470644 | controller | Collecting pytest-forked 2025-10-11 00:21:10.533920 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-10-11 00:21:10.643318 | controller | Collecting py 2025-10-11 00:21:10.651977 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-10-11 00:21:10.688283 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.4 MB/s eta 0:00:00 2025-10-11 00:21:10.954867 | controller | Collecting pytest>=3.10 2025-10-11 00:21:10.961815 | controller | Downloading pytest-8.3.5-py3-none-any.whl (343 kB) 2025-10-11 00:21:10.999914 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 10.4 MB/s eta 0:00:00 2025-10-11 00:21:11.119857 | controller | Collecting tomli>=1 2025-10-11 00:21:11.125953 | controller | Downloading tomli-2.3.0-py3-none-any.whl (14 kB) 2025-10-11 00:21:11.196572 | controller | Collecting pluggy<2,>=1.5 2025-10-11 00:21:11.207129 | controller | Downloading pluggy-1.5.0-py3-none-any.whl (20 kB) 2025-10-11 00:21:11.257515 | controller | Collecting iniconfig 2025-10-11 00:21:11.268351 | controller | Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB) 2025-10-11 00:21:11.363931 | controller | Collecting packaging 2025-10-11 00:21:11.374680 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-10-11 00:21:11.387233 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.5 MB/s eta 0:00:00 2025-10-11 00:21:11.453098 | controller | Collecting exceptiongroup>=1.0.0rc8 2025-10-11 00:21:11.460515 | controller | Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB) 2025-10-11 00:21:11.577575 | controller | Collecting typing-extensions>=4.6.0 2025-10-11 00:21:11.589502 | controller | Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB) 2025-10-11 00:21:11.601416 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 4.2 MB/s eta 0:00:00 2025-10-11 00:21:11.748935 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked 2025-10-11 00:21:12.853833 | controller | Successfully installed exceptiongroup-1.3.0 iniconfig-2.1.0 packaging-25.0 pluggy-1.5.0 py-1.11.0 pytest-8.3.5 pytest-forked-1.6.0 tomli-2.3.0 typing-extensions-4.13.2 2025-10-11 00:21:12.858641 | controller | 2025-10-11 00:21:13.129513 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1 2025-10-11 00:21:13.129567 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-10-11 00:21:13.524598 | controller | ok: Runtime: 0:00:03.620956 2025-10-11 00:21:13.533098 | 2025-10-11 00:21:13.533243 | TASK [Update pip] 2025-10-11 00:21:16.010804 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2) 2025-10-11 00:21:16.534028 | controller | Collecting pip 2025-10-11 00:21:16.688566 | controller | Downloading pip-25.0.1-py3-none-any.whl (1.8 MB) 2025-10-11 00:21:16.833016 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 14.8 MB/s eta 0:00:00 2025-10-11 00:21:17.021327 | controller | Installing collected packages: pip 2025-10-11 00:21:17.021682 | controller | Attempting uninstall: pip 2025-10-11 00:21:17.022751 | controller | Found existing installation: pip 22.2.2 2025-10-11 00:21:17.573498 | controller | Uninstalling pip-22.2.2: 2025-10-11 00:21:17.651930 | controller | Successfully uninstalled pip-22.2.2 2025-10-11 00:21:20.114788 | controller | Successfully installed pip-25.0.1 2025-10-11 00:21:20.928187 | controller | ok: Runtime: 0:00:05.719855 2025-10-11 00:21:20.937208 | 2025-10-11 00:21:20.937354 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-10-11 00:21:22.281462 | controller | changed 2025-10-11 00:21:22.288598 | 2025-10-11 00:21:22.288718 | TASK [Install ansible into virtualenv] 2025-10-11 00:21:24.168944 | controller | Processing ./src/github.com/ansible/ansible 2025-10-11 00:21:26.247970 | controller | Preparing metadata (setup.py): started 2025-10-11 00:21:26.248030 | controller | Preparing metadata (setup.py): finished with status 'done' 2025-10-11 00:21:26.349622 | controller | Collecting jinja2 (from ansible==2.9.27.post0) 2025-10-11 00:21:26.370363 | controller | Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB) 2025-10-11 00:21:26.479375 | controller | Collecting PyYAML (from ansible==2.9.27.post0) 2025-10-11 00:21:26.489003 | controller | Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl.metadata (2.1 kB) 2025-10-11 00:21:27.034708 | controller | Collecting cryptography (from ansible==2.9.27.post0) 2025-10-11 00:21:27.042786 | controller | Downloading cryptography-46.0.2-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB) 2025-10-11 00:21:27.351199 | controller | Collecting cffi>=1.14 (from cryptography->ansible==2.9.27.post0) 2025-10-11 00:21:27.358442 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB) 2025-10-11 00:21:27.376392 | controller | Requirement already satisfied: typing-extensions>=4.13.2 in ./venv/lib/python3.8/site-packages (from cryptography->ansible==2.9.27.post0) (4.13.2) 2025-10-11 00:21:27.518669 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible==2.9.27.post0) 2025-10-11 00:21:27.525216 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB) 2025-10-11 00:21:27.569052 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible==2.9.27.post0) 2025-10-11 00:21:27.574054 | controller | Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes) 2025-10-11 00:21:27.598644 | controller | Downloading cryptography-46.0.2-cp38-abi3-manylinux_2_34_x86_64.whl (4.5 MB) 2025-10-11 00:21:27.656645 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 86.3 MB/s eta 0:00:00 2025-10-11 00:21:27.668612 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB) 2025-10-11 00:21:27.691004 | controller | Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl (806 kB) 2025-10-11 00:21:27.718033 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 806.0/806.0 kB 25.9 MB/s eta 0:00:00 2025-10-11 00:21:27.724218 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB) 2025-10-11 00:21:27.747437 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB) 2025-10-11 00:21:27.757030 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB) 2025-10-11 00:21:27.794408 | controller | Building wheels for collected packages: ansible 2025-10-11 00:21:27.795392 | controller | Building wheel for ansible (setup.py): started 2025-10-11 00:21:39.325982 | controller | Building wheel for ansible (setup.py): finished with status 'done' 2025-10-11 00:21:39.348594 | controller | Created wheel for ansible: filename=ansible-2.9.27.post0-py3-none-any.whl size=16207514 sha256=2a6f99b0047acc96b86cc27a1f76e38c92144dcdd19686bee46617342a63cb8a 2025-10-11 00:21:39.348854 | controller | Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-tto22r3b/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7 2025-10-11 00:21:39.436259 | controller | Successfully built ansible 2025-10-11 00:21:39.636666 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible 2025-10-11 00:21:56.665988 | controller | Successfully installed MarkupSafe-2.1.5 PyYAML-6.0.3 ansible-2.9.27.post0 cffi-1.17.1 cryptography-46.0.2 jinja2-3.1.6 pycparser-2.23 2025-10-11 00:21:57.192216 | controller | ok: Runtime: 0:00:33.436451 2025-10-11 00:21:57.203198 | 2025-10-11 00:21:57.203372 | TASK [Setup download-artifact-fork role] 2025-10-11 00:21:57.225380 | controller | ok 2025-10-11 00:21:57.244671 | 2025-10-11 00:21:57.244788 | TASK [download-artifact-fork : Parse inventory response] 2025-10-11 00:21:57.297508 | controller | ok 2025-10-11 00:21:57.306639 | 2025-10-11 00:21:57.306768 | TASK [download-artifact-fork : Fetch info from Zuul API] 2025-10-11 00:21:57.333579 | controller | skipping: Conditional result was False 2025-10-11 00:21:57.343344 | 2025-10-11 00:21:57.343461 | TASK [download-artifact-fork : Parse build response] 2025-10-11 00:21:57.369712 | controller | skipping: Conditional result was False 2025-10-11 00:21:57.379518 | 2025-10-11 00:21:57.380086 | TASK [download-artifact-fork : Ensure artifacts directory exists] 2025-10-11 00:21:58.231827 | controller | changed 2025-10-11 00:21:58.239698 | 2025-10-11 00:21:58.239791 | LOOP [download-artifact-fork : Download archive by type] 2025-10-11 00:21:58.283208 | controller | skipping: Conditional result was False 2025-10-11 00:21:58.283478 | 2025-10-11 00:22:00.402274 | controller | changed: OK (20214 bytes) 2025-10-11 00:22:00.425384 | 2025-10-11 00:22:00.425639 | TASK [deploy-artifacts : define __collections] 2025-10-11 00:22:00.461882 | controller | ok 2025-10-11 00:22:00.467494 | 2025-10-11 00:22:00.467586 | LOOP [deploy-artifacts : Create list of collections] 2025-10-11 00:22:00.496644 | controller | skipping: Conditional result was False 2025-10-11 00:22:00.508909 | controller | ok: 2025-10-11 00:22:00.509043 | controller | { 2025-10-11 00:22:00.509081 | controller | "branch": "main", 2025-10-11 00:22:00.509109 | controller | "job": "build-ansible-collection", 2025-10-11 00:22:00.509134 | controller | "metadata": { 2025-10-11 00:22:00.509158 | controller | "type": "ansible_collection", 2025-10-11 00:22:00.509182 | controller | "version": "5.0.0" 2025-10-11 00:22:00.509205 | controller | }, 2025-10-11 00:22:00.509227 | controller | "name": "ansible.network", 2025-10-11 00:22:00.509249 | controller | "project": "ansible-collections/ansible.network", 2025-10-11 00:22:00.509271 | controller | "url": "https://58dfcab4ab32e207702c-9c3e30aeca6aa8032f977aa968e7fa1b.ssl.cf2.rackcdn.com/ansible/86ec565e89914d5f9aa3032eeb2ff71d/artifacts/ansible-network-5.0.0.tar.gz" 2025-10-11 00:22:00.509301 | controller | } 2025-10-11 00:22:00.568275 | 2025-10-11 00:22:00.568416 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy] 2025-10-11 00:22:01.755813 | controller | Process install dependency map 2025-10-11 00:22:45.350601 | controller | |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-Starting collection install process 2025-10-11 00:22:45.452950 | controller | |Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network' 2025-10-11 00:22:45.553322 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2025-10-11 00:22:53.431129 | controller | /-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils' 2025-10-11 00:22:55.464939 | controller | |/-\|/-\|/-\|/-\|/-\Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos' 2025-10-11 00:23:21.314700 | controller | |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|Installing 'cisco.ios:11.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios' 2025-10-11 00:23:36.491734 | controller | /-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\ERROR! Unexpected Exception, this is probably a bug: The read operation timed out 2025-10-11 00:23:36.491807 | controller | to see the full traceback, use -vvv 2025-10-11 00:23:37.001445 | controller | ERROR 2025-10-11 00:23:37.001624 | controller | { 2025-10-11 00:23:37.001661 | controller | "delta": "0:01:35.313662", 2025-10-11 00:23:37.001688 | controller | "end": "2025-10-11 00:23:36.593118", 2025-10-11 00:23:37.001711 | controller | "msg": "non-zero return code", 2025-10-11 00:23:37.001733 | controller | "rc": 250, 2025-10-11 00:23:37.001756 | controller | "start": "2025-10-11 00:22:01.279456" 2025-10-11 00:23:37.001777 | controller | } failure 2025-10-11 00:23:37.003898 | 2025-10-11 00:23:37.003955 | PLAY RECAP 2025-10-11 00:23:37.004032 | controller | ok: 44 changed: 24 unreachable: 0 failed: 1 skipped: 17 rescued: 0 ignored: 0 2025-10-11 00:23:37.004071 | 2025-10-11 00:23:37.166355 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-10-11 00:23:37.167328 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-11 00:23:37.763368 | 2025-10-11 00:23:37.763492 | PLAY [all] 2025-10-11 00:23:37.785425 | 2025-10-11 00:23:37.785568 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-11 00:23:40.839113 | controller | changed: non-zero return code 2025-10-11 00:23:40.846996 | 2025-10-11 00:23:40.847132 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-11 00:23:40.872007 | controller | skipping: Conditional result was False 2025-10-11 00:23:40.878189 | 2025-10-11 00:23:40.878260 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-11 00:23:40.910511 | 2025-10-11 00:23:40.910704 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-11 00:23:40.955618 | 2025-10-11 00:23:40.955848 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-11 00:23:40.981831 | controller | skipping: Conditional result was False 2025-10-11 00:23:40.993200 | 2025-10-11 00:23:40.993363 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-11 00:23:41.027939 | 2025-10-11 00:23:41.028179 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-11 00:23:41.043789 | controller | skipping: Conditional result was False 2025-10-11 00:23:41.054698 | 2025-10-11 00:23:41.054817 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-11 00:23:41.069134 | controller | skipping: Conditional result was False 2025-10-11 00:23:41.078228 | 2025-10-11 00:23:41.078323 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-11 00:23:41.102858 | controller | skipping: Conditional result was False 2025-10-11 00:23:41.143307 | 2025-10-11 00:23:41.143421 | PLAY RECAP 2025-10-11 00:23:41.143478 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-11 00:23:41.143507 | 2025-10-11 00:23:41.255959 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-11 00:23:41.257175 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-10-11 00:23:42.026924 | 2025-10-11 00:23:42.027072 | PLAY [all:!appliance*] 2025-10-11 00:23:42.049210 | 2025-10-11 00:23:42.049336 | TASK [unregister the node] 2025-10-11 00:23:42.406300 | controller | skipping: Conditional result was False 2025-10-11 00:23:42.413016 | 2025-10-11 00:23:42.413183 | TASK [include_role : fetch-output] 2025-10-11 00:23:42.464357 | controller | ok 2025-10-11 00:23:42.485792 | 2025-10-11 00:23:42.485940 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-11 00:23:42.541295 | controller | skipping: Conditional result was False 2025-10-11 00:23:42.547737 | 2025-10-11 00:23:42.547817 | TASK [fetch-output : Set log path for single node] 2025-10-11 00:23:42.584798 | controller | ok 2025-10-11 00:23:42.596529 | 2025-10-11 00:23:42.596638 | LOOP [fetch-output : Ensure local output dirs] 2025-10-11 00:23:43.066459 | controller -> localhost | ok: "/var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/logs" 2025-10-11 00:23:43.310307 | controller -> localhost | changed: "/var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/artifacts" 2025-10-11 00:23:43.573921 | controller -> localhost | changed: "/var/lib/zuul/builds/d395a2f5675d4f02af5110fed118694f/work/docs" 2025-10-11 00:23:43.586892 | 2025-10-11 00:23:43.587057 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-11 00:23:45.848708 | controller | changed: 2025-10-11 00:23:45.849107 | controller | .d..t...... ./ 2025-10-11 00:23:45.849171 | controller | cd+++++++++ controller/ 2025-10-11 00:23:45.849240 | controller | changed: All items complete 2025-10-11 00:23:45.849288 | 2025-10-11 00:23:47.937269 | controller | changed: .d..t...... ./ 2025-10-11 00:23:49.978918 | controller | changed: .d..t...... ./ 2025-10-11 00:23:50.000091 | 2025-10-11 00:23:50.000229 | TASK [include_role : fetch-output-openshift] 2025-10-11 00:23:50.015559 | controller | skipping: Conditional result was False 2025-10-11 00:23:50.024610 | 2025-10-11 00:23:50.024741 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-11 00:23:50.064198 | controller | skipping: Conditional result was False 2025-10-11 00:23:50.073775 | controller | skipping: Conditional result was False 2025-10-11 00:23:50.111070 | 2025-10-11 00:23:50.111192 | PLAY [localhost] 2025-10-11 00:23:50.125759 | 2025-10-11 00:23:50.125884 | TASK [Run Zuul manifest role] 2025-10-11 00:23:50.144678 | localhost | ok 2025-10-11 00:23:50.160693 | 2025-10-11 00:23:50.160852 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-11 00:23:50.597391 | localhost | changed 2025-10-11 00:23:50.602653 | 2025-10-11 00:23:50.602768 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-11 00:23:50.641360 | localhost | ok 2025-10-11 00:23:50.650718 | 2025-10-11 00:23:50.650809 | TASK [Set zuul-log-path fact] 2025-10-11 00:23:50.670872 | localhost | ok 2025-10-11 00:23:50.713844 | 2025-10-11 00:23:50.713965 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-11 00:23:50.742532 | localhost | ok 2025-10-11 00:23:50.751827 | 2025-10-11 00:23:50.751927 | LOOP [Run upload-logs-swift role] 2025-10-11 00:23:50.786850 | localhost | Output suppressed because no_log was given 2025-10-11 00:23:50.812464 | 2025-10-11 00:23:50.812579 | TASK [Set zuul-log-path fact] 2025-10-11 00:23:50.836988 | localhost | skipping: Conditional result was False 2025-10-11 00:23:50.843731 | 2025-10-11 00:23:50.843823 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-10-11 00:23:51.246030 | localhost -> localhost | ok: Runtime: 0:00:00.006030 2025-10-11 00:23:51.253128 | 2025-10-11 00:23:51.253263 | TASK [upload-logs-swift : Upload logs to swift]