2025-12-01 00:06:51.666091 | Job console starting... 2025-12-01 00:06:51.677943 | Updating repositories 2025-12-01 00:06:51.842411 | Preparing job workspace 2025-12-01 00:07:00.999394 | Running Ansible setup... 2025-12-01 00:07:05.890093 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-01 00:07:06.488388 | 2025-12-01 00:07:06.488510 | PLAY [localhost] 2025-12-01 00:07:06.496819 | 2025-12-01 00:07:06.496891 | TASK [Gathering Facts] 2025-12-01 00:07:07.523052 | localhost | ok 2025-12-01 00:07:07.547313 | 2025-12-01 00:07:07.547546 | TASK [Setup log path fact] 2025-12-01 00:07:07.569280 | localhost | ok 2025-12-01 00:07:07.588708 | 2025-12-01 00:07:07.588829 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 00:07:07.617633 | localhost | ok 2025-12-01 00:07:07.625973 | 2025-12-01 00:07:07.626079 | TASK [emit-job-header : Print job information] 2025-12-01 00:07:07.674668 | # Job Information 2025-12-01 00:07:07.674828 | Ansible Version: 2.15.12 2025-12-01 00:07:07.674860 | Job: ansible-test-sanity-docker-devel 2025-12-01 00:07:07.674882 | Pipeline: periodic 2025-12-01 00:07:07.674902 | Executor: ze01.softwarefactory-project.io 2025-12-01 00:07:07.674920 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-01 00:07:07.674942 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/ac4/ansible/ac48566651d04a6c9b119d2b72614100/ 2025-12-01 00:07:07.674961 | Event ID: 7f239586727e4cf3b26e006c8a5b9dc9 2025-12-01 00:07:07.678845 | 2025-12-01 00:07:07.678912 | LOOP [emit-job-header : Print node information] 2025-12-01 00:07:07.801424 | localhost | ok: 2025-12-01 00:07:07.801634 | localhost | # Node Information 2025-12-01 00:07:07.801673 | localhost | Inventory Hostname: controller 2025-12-01 00:07:07.801702 | localhost | Hostname: np0005540468 2025-12-01 00:07:07.801731 | localhost | Username: zuul 2025-12-01 00:07:07.801764 | localhost | Distro: Fedora 37 2025-12-01 00:07:07.801792 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-01 00:07:07.801818 | localhost | Region: ca-ymq-1 2025-12-01 00:07:07.801843 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-01 00:07:07.801866 | localhost | Product Name: OpenStack Nova 2025-12-01 00:07:07.801891 | localhost | Interface IP: 162.253.55.186 2025-12-01 00:07:07.814191 | 2025-12-01 00:07:07.814299 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-01 00:07:08.227664 | localhost -> localhost | changed 2025-12-01 00:07:08.233228 | 2025-12-01 00:07:08.233318 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-01 00:07:09.273558 | localhost -> localhost | changed 2025-12-01 00:07:09.309281 | 2025-12-01 00:07:09.309381 | PLAY [all:!appliance*] 2025-12-01 00:07:09.325386 | 2025-12-01 00:07:09.325453 | TASK [include_role : start-zuul-console] 2025-12-01 00:07:09.343700 | controller | ok 2025-12-01 00:07:09.357132 | 2025-12-01 00:07:09.357201 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-01 00:07:09.732861 | controller | ok 2025-12-01 00:07:09.743271 | 2025-12-01 00:07:09.743341 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-01 00:07:10.527582 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-01 00:07:10.541540 | 2025-12-01 00:07:10.541647 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-01 00:07:11.080818 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.094581 | 2025-12-01 00:07:11.094746 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-01 00:07:11.132067 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.145499 | 2025-12-01 00:07:11.145671 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-01 00:07:11.172508 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.185824 | 2025-12-01 00:07:11.185979 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-01 00:07:11.212283 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.218867 | 2025-12-01 00:07:11.218976 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-01 00:07:11.255829 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.265574 | 2025-12-01 00:07:11.265724 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-01 00:07:11.290662 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.310175 | 2025-12-01 00:07:11.310321 | TASK [Disable Fedora Modular] 2025-12-01 00:07:11.557340 | controller | changed 2025-12-01 00:07:11.565398 | 2025-12-01 00:07:11.565526 | TASK [Enable EPEL] 2025-12-01 00:07:11.590518 | controller | skipping: Conditional result was False 2025-12-01 00:07:11.596953 | 2025-12-01 00:07:11.597062 | TASK [Register the RHEL node] 2025-12-01 00:07:12.144229 | 2025-12-01 00:07:12.144506 | TASK [Show the subscription-manager status] 2025-12-01 00:07:12.720451 | controller | skipping: Conditional result was False 2025-12-01 00:07:12.729744 | 2025-12-01 00:07:12.729831 | TASK [Enable EPEL on RHEL] 2025-12-01 00:07:13.279548 | controller | skipping: Conditional result was False 2025-12-01 00:07:13.292380 | 2025-12-01 00:07:13.292546 | TASK [Install git and tox] 2025-12-01 00:08:42.615439 | controller | changed 2025-12-01 00:08:42.625759 | 2025-12-01 00:08:42.626005 | TASK [include_role : prepare-workspace] 2025-12-01 00:08:42.661620 | controller | ok 2025-12-01 00:08:42.692977 | 2025-12-01 00:08:42.693120 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-01 00:08:42.957235 | controller | ok 2025-12-01 00:08:42.974599 | 2025-12-01 00:08:42.974798 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-01 00:14:12.695919 | controller | Output suppressed because no_log was given 2025-12-01 00:14:12.709799 | 2025-12-01 00:14:12.709904 | TASK [include_role : prepare-workspace-openshift] 2025-12-01 00:14:12.735007 | controller | skipping: Conditional result was False 2025-12-01 00:14:12.765249 | 2025-12-01 00:14:12.765332 | PLAY [all:!appliance] 2025-12-01 00:14:12.784560 | 2025-12-01 00:14:12.784626 | TASK [Run add-build-sshkey role (RSA)] 2025-12-01 00:14:12.815740 | controller | ok 2025-12-01 00:14:12.837634 | 2025-12-01 00:14:12.837749 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-01 00:14:13.065740 | controller -> localhost | ok 2025-12-01 00:14:13.072672 | 2025-12-01 00:14:13.072747 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-01 00:14:13.094139 | controller | ok 2025-12-01 00:14:13.118498 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-01 00:14:13.128603 | 2025-12-01 00:14:13.128696 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-01 00:14:13.632967 | controller -> localhost | Generating public/private rsa key pair. 2025-12-01 00:14:13.633207 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_rsa. 2025-12-01 00:14:13.633249 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_rsa.pub. 2025-12-01 00:14:13.633279 | controller -> localhost | The key fingerprint is: 2025-12-01 00:14:13.633308 | controller -> localhost | SHA256:c/zbk0CnO7zBaViU6u1ZN2oh4SJuu22WD8ywYiyptmE zuul-build-sshkey 2025-12-01 00:14:13.633335 | controller -> localhost | The key's randomart image is: 2025-12-01 00:14:13.633362 | controller -> localhost | +---[RSA 2048]----+ 2025-12-01 00:14:13.633388 | controller -> localhost | | | 2025-12-01 00:14:13.633415 | controller -> localhost | | . | 2025-12-01 00:14:13.633442 | controller -> localhost | | o | 2025-12-01 00:14:13.633468 | controller -> localhost | | . +. . | 2025-12-01 00:14:13.633493 | controller -> localhost | | .S =.oo | 2025-12-01 00:14:13.633531 | controller -> localhost | | o .== Ooo | 2025-12-01 00:14:13.633562 | controller -> localhost | | E o +...+=.Oooo.| 2025-12-01 00:14:13.633589 | controller -> localhost | |..o o .o.+.o+B+..| 2025-12-01 00:14:13.633615 | controller -> localhost | |.o. .o=...*+.. | 2025-12-01 00:14:13.633645 | controller -> localhost | +----[SHA256]-----+ 2025-12-01 00:14:13.633705 | controller -> localhost | ok: Runtime: 0:00:00.054378 2025-12-01 00:14:13.643388 | 2025-12-01 00:14:13.643491 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-01 00:14:13.677363 | controller | ok 2025-12-01 00:14:13.692914 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-01 00:14:13.706708 | 2025-12-01 00:14:13.706839 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-01 00:14:13.732804 | controller | skipping: Conditional result was False 2025-12-01 00:14:13.740973 | 2025-12-01 00:14:13.741117 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-01 00:14:14.355748 | controller | changed 2025-12-01 00:14:14.362076 | 2025-12-01 00:14:14.362142 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-01 00:14:14.598896 | controller | ok 2025-12-01 00:14:14.604880 | 2025-12-01 00:14:14.604955 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-01 00:14:15.217295 | controller | changed 2025-12-01 00:14:15.223640 | 2025-12-01 00:14:15.223750 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-01 00:14:15.817418 | controller | changed 2025-12-01 00:14:15.824410 | 2025-12-01 00:14:15.824476 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-01 00:14:15.849292 | controller | skipping: Conditional result was False 2025-12-01 00:14:15.858818 | 2025-12-01 00:14:15.858950 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-01 00:14:16.251191 | controller -> localhost | changed 2025-12-01 00:14:16.279705 | 2025-12-01 00:14:16.279875 | TASK [add-build-sshkey : Add back temp key] 2025-12-01 00:14:16.593151 | controller -> localhost | Identity added: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_rsa (zuul-build-sshkey) 2025-12-01 00:14:16.593373 | controller -> localhost | ok: Runtime: 0:00:00.008833 2025-12-01 00:14:16.600094 | 2025-12-01 00:14:16.600163 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-01 00:14:16.964386 | controller | ok 2025-12-01 00:14:16.970149 | 2025-12-01 00:14:16.970244 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-01 00:14:16.994809 | controller | skipping: Conditional result was False 2025-12-01 00:14:17.027752 | 2025-12-01 00:14:17.027895 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-01 00:14:17.054775 | controller | ok 2025-12-01 00:14:17.082827 | 2025-12-01 00:14:17.083007 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-01 00:14:17.384730 | controller -> localhost | ok 2025-12-01 00:14:17.391472 | 2025-12-01 00:14:17.391547 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-01 00:14:17.413614 | controller | ok 2025-12-01 00:14:17.425628 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-01 00:14:17.433033 | 2025-12-01 00:14:17.433117 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-01 00:14:17.724136 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-01 00:14:17.724331 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_ecdsa. 2025-12-01 00:14:17.724361 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_ecdsa.pub. 2025-12-01 00:14:17.724390 | controller -> localhost | The key fingerprint is: 2025-12-01 00:14:17.724413 | controller -> localhost | SHA256:mX7K4AaLCGhczNck049TwjZkVWPJigKVQMzeJ7fTrgw zuul-build-sshkey 2025-12-01 00:14:17.724434 | controller -> localhost | The key's randomart image is: 2025-12-01 00:14:17.724453 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-01 00:14:17.724473 | controller -> localhost | | +oo.=o..o+. | 2025-12-01 00:14:17.724492 | controller -> localhost | | + +.B ..o. | 2025-12-01 00:14:17.724511 | controller -> localhost | | + o * B . | 2025-12-01 00:14:17.724530 | controller -> localhost | | = = B = | 2025-12-01 00:14:17.724548 | controller -> localhost | |o . . = S | 2025-12-01 00:14:17.724566 | controller -> localhost | |oo . + . | 2025-12-01 00:14:17.724585 | controller -> localhost | |o. . E. + . | 2025-12-01 00:14:17.724604 | controller -> localhost | |. . ..+o + | 2025-12-01 00:14:17.724623 | controller -> localhost | | ..o+ | 2025-12-01 00:14:17.724641 | controller -> localhost | +----[SHA256]-----+ 2025-12-01 00:14:17.724701 | controller -> localhost | ok: Runtime: 0:00:00.016246 2025-12-01 00:14:17.731891 | 2025-12-01 00:14:17.731960 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-01 00:14:17.761385 | controller | ok 2025-12-01 00:14:17.774607 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-01 00:14:17.785413 | 2025-12-01 00:14:17.785500 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-01 00:14:17.800053 | controller | skipping: Conditional result was False 2025-12-01 00:14:17.807320 | 2025-12-01 00:14:17.807386 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-01 00:14:18.070370 | controller | changed 2025-12-01 00:14:18.087867 | 2025-12-01 00:14:18.088089 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-01 00:14:18.309078 | controller | ok 2025-12-01 00:14:18.319733 | 2025-12-01 00:14:18.319896 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-01 00:14:19.004932 | controller | changed 2025-12-01 00:14:19.018586 | 2025-12-01 00:14:19.018729 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-01 00:14:19.674765 | controller | changed 2025-12-01 00:14:19.684994 | 2025-12-01 00:14:19.685226 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-01 00:14:19.753333 | controller | skipping: Conditional result was False 2025-12-01 00:14:19.806345 | 2025-12-01 00:14:19.806484 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-01 00:14:20.037302 | controller -> localhost | changed 2025-12-01 00:14:20.062229 | 2025-12-01 00:14:20.062361 | TASK [add-build-sshkey : Add back temp key] 2025-12-01 00:14:20.374776 | controller -> localhost | Identity added: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/ac48566651d04a6c9b119d2b72614100_id_ecdsa (zuul-build-sshkey) 2025-12-01 00:14:20.375236 | controller -> localhost | ok: Runtime: 0:00:00.014226 2025-12-01 00:14:20.391682 | 2025-12-01 00:14:20.391891 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-01 00:14:20.619164 | controller | ok 2025-12-01 00:14:20.626923 | 2025-12-01 00:14:20.627132 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-01 00:14:20.663346 | controller | skipping: Conditional result was False 2025-12-01 00:14:20.683423 | 2025-12-01 00:14:20.683601 | TASK [include_role : remove-zuul-sshkey] 2025-12-01 00:14:20.709454 | controller | skipping: Conditional result was False 2025-12-01 00:14:20.721515 | 2025-12-01 00:14:20.721671 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 00:14:20.960992 | controller | ok: "logs" 2025-12-01 00:14:20.961638 | controller | ok: All items complete 2025-12-01 00:14:20.962112 | 2025-12-01 00:14:21.153963 | controller | ok: "artifacts" 2025-12-01 00:14:21.323978 | controller | ok: "docs" 2025-12-01 00:14:21.336670 | 2025-12-01 00:14:21.336821 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 00:14:21.585483 | controller | changed: "logs" 2025-12-01 00:14:21.777846 | controller | changed: "artifacts" 2025-12-01 00:14:21.970811 | controller | changed: "docs" 2025-12-01 00:14:22.031849 | 2025-12-01 00:14:22.031968 | PLAY RECAP 2025-12-01 00:14:22.032049 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-01 00:14:22.032093 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 00:14:22.032118 | 2025-12-01 00:14:22.151251 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-01 00:14:22.153282 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 00:14:22.738307 | 2025-12-01 00:14:22.738417 | PLAY [all] 2025-12-01 00:14:22.760660 | 2025-12-01 00:14:22.760762 | TASK [Install binary dependencies] 2025-12-01 00:14:22.801811 | controller | ok 2025-12-01 00:14:22.822048 | 2025-12-01 00:14:22.822167 | TASK [bindep : Include find tasks] 2025-12-01 00:14:22.861945 | controller | ok 2025-12-01 00:14:22.878636 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-01 00:14:22.893063 | 2025-12-01 00:14:22.893204 | TASK [bindep : Look for bindep.txt] 2025-12-01 00:14:23.423059 | controller | ok 2025-12-01 00:14:23.435979 | 2025-12-01 00:14:23.436218 | TASK [bindep : Define bindep_file fact] 2025-12-01 00:14:23.463780 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.477176 | 2025-12-01 00:14:23.477327 | TASK [bindep : Look for other-requirements.txt] 2025-12-01 00:14:23.697488 | controller | ok 2025-12-01 00:14:23.706714 | 2025-12-01 00:14:23.706854 | TASK [bindep : Define bindep_file fact] 2025-12-01 00:14:23.733944 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.747742 | 2025-12-01 00:14:23.747888 | TASK [bindep : Look for bindep fallback file] 2025-12-01 00:14:23.774710 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.789291 | 2025-12-01 00:14:23.789439 | TASK [bindep : Define bindep_file fact] 2025-12-01 00:14:23.816204 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.829417 | 2025-12-01 00:14:23.829566 | TASK [bindep : Include bindep tasks] 2025-12-01 00:14:23.855794 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.868707 | 2025-12-01 00:14:23.868840 | TASK [bindep : Include install tasks] 2025-12-01 00:14:23.895269 | controller | skipping: Conditional result was False 2025-12-01 00:14:23.909157 | 2025-12-01 00:14:23.909303 | LOOP [bindep : Include package tasks] 2025-12-01 00:14:23.990103 | 2025-12-01 00:14:23.990361 | TASK [Run test-setup role] 2025-12-01 00:14:24.025110 | controller | ok 2025-12-01 00:14:24.053343 | 2025-12-01 00:14:24.053454 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-01 00:14:24.260893 | controller | ok 2025-12-01 00:14:24.271439 | 2025-12-01 00:14:24.271594 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-01 00:14:24.822505 | controller | skipping: Conditional result was False 2025-12-01 00:14:24.876637 | 2025-12-01 00:14:24.876776 | PLAY RECAP 2025-12-01 00:14:24.876851 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-01 00:14:24.876894 | 2025-12-01 00:14:24.983715 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 00:14:24.985758 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-01 00:14:25.631392 | 2025-12-01 00:14:25.631523 | PLAY [controller] 2025-12-01 00:14:25.661919 | 2025-12-01 00:14:25.662105 | TASK [Create the /root directory] 2025-12-01 00:14:26.211796 | controller | ok 2025-12-01 00:14:26.224053 | 2025-12-01 00:14:26.224159 | TASK [Install glibc-langpack-en] 2025-12-01 00:14:30.088119 | controller | ok: Nothing to do 2025-12-01 00:14:30.098909 | 2025-12-01 00:14:30.099082 | TASK [Ensure controller directory exists] 2025-12-01 00:14:30.331826 | controller | changed 2025-12-01 00:14:30.345928 | 2025-12-01 00:14:30.346106 | TASK [Install container runtime] 2025-12-01 00:14:30.395730 | controller | ok 2025-12-01 00:14:30.453873 | 2025-12-01 00:14:30.453987 | LOOP [ensure-podman : Find distribution installation] 2025-12-01 00:14:30.486426 | controller | ok: "/var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-01 00:14:30.495599 | controller | included: /var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-01 00:14:30.502282 | 2025-12-01 00:14:30.502350 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-01 00:15:39.535840 | controller | changed 2025-12-01 00:15:39.549245 | 2025-12-01 00:15:39.549699 | TASK [ensure-podman : Fetch podman version] 2025-12-01 00:15:40.100515 | controller | Client: Podman Engine 2025-12-01 00:15:40.123934 | controller | Version: 4.6.2 2025-12-01 00:15:40.123964 | controller | API Version: 4.6.2 2025-12-01 00:15:40.123973 | controller | Go Version: go1.19.12 2025-12-01 00:15:40.123990 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-01 00:15:40.123997 | controller | OS/Arch: linux/amd64 2025-12-01 00:15:40.609494 | controller | ok: Runtime: 0:00:00.182372 2025-12-01 00:15:40.621626 | 2025-12-01 00:15:40.621743 | TASK [ensure-podman : Print podman version installed] 2025-12-01 00:15:40.654632 | Podman version: Client: Podman Engine 2025-12-01 00:15:40.654780 | Version: 4.6.2 2025-12-01 00:15:40.654808 | API Version: 4.6.2 2025-12-01 00:15:40.654829 | Go Version: go1.19.12 2025-12-01 00:15:40.654847 | Built: Mon Aug 28 19:38:31 2023 2025-12-01 00:15:40.654866 | OS/Arch: linux/amd64 2025-12-01 00:15:40.660927 | 2025-12-01 00:15:40.661044 | TASK [ensure-podman : Validate podman engine] 2025-12-01 00:15:41.196804 | controller | skipping: Conditional result was False 2025-12-01 00:15:41.203566 | 2025-12-01 00:15:41.203653 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-01 00:15:41.217394 | controller | skipping: Conditional result was False 2025-12-01 00:15:41.238297 | 2025-12-01 00:15:41.238458 | TASK [Ensure python3.8 is present] 2025-12-01 00:15:41.252259 | controller | skipping: Conditional result was False 2025-12-01 00:15:41.263463 | 2025-12-01 00:15:41.263550 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-01 00:15:41.283196 | controller | ok 2025-12-01 00:15:41.314340 | 2025-12-01 00:15:41.314496 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-01 00:15:42.744403 | controller | ok: Nothing to do 2025-12-01 00:15:42.755209 | 2025-12-01 00:15:42.755344 | TASK [our-ensure-python : Also install python3-devel] 2025-12-01 00:15:53.535794 | controller | changed 2025-12-01 00:15:53.562581 | 2025-12-01 00:15:53.562771 | TASK [Run ensure-virtualenv role] 2025-12-01 00:15:53.587073 | controller | ok 2025-12-01 00:15:53.618216 | 2025-12-01 00:15:53.618360 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-01 00:15:53.851653 | controller | /usr/bin/virtualenv 2025-12-01 00:15:54.181620 | controller | ok: Runtime: 0:00:00.004577 2025-12-01 00:15:54.187888 | 2025-12-01 00:15:54.187968 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-01 00:15:54.207583 | controller | skipping: Conditional result was False 2025-12-01 00:15:54.207948 | controller | ok: All items complete 2025-12-01 00:15:54.208005 | 2025-12-01 00:15:54.223894 | 2025-12-01 00:15:54.224074 | TASK [Find the full path of the Python interpreter] 2025-12-01 00:15:54.435569 | controller | /usr/bin/python3 2025-12-01 00:15:54.759608 | controller | ok 2025-12-01 00:15:54.772318 | 2025-12-01 00:15:54.772457 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-01 00:15:55.705484 | controller | created virtual environment CPython3.11.0.final.0-64 in 562ms 2025-12-01 00:15:55.729507 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-01 00:15:55.729548 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2025-12-01 00:15:55.729558 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-01 00:15:55.729572 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-01 00:15:55.828670 | controller | changed 2025-12-01 00:15:55.842332 | 2025-12-01 00:15:55.842465 | TASK [Set selinux package] 2025-12-01 00:15:55.876241 | controller | ok 2025-12-01 00:15:55.890184 | 2025-12-01 00:15:55.890363 | TASK [Set selinux package (Fedora)] 2025-12-01 00:15:55.921561 | controller | ok 2025-12-01 00:15:55.927543 | 2025-12-01 00:15:55.927606 | TASK [Install selinux into virtualenv] 2025-12-01 00:15:57.161240 | controller | Collecting selinux-please-lie-to-me 2025-12-01 00:15:57.199588 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-01 00:15:57.507231 | controller | Collecting setuptools<50.0.0 2025-12-01 00:15:57.512786 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-01 00:15:57.548111 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.6 MB/s eta 0:00:00 2025-12-01 00:15:57.634335 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-01 00:15:57.634565 | controller | Attempting uninstall: setuptools 2025-12-01 00:15:57.637008 | controller | Found existing installation: setuptools 62.6.0 2025-12-01 00:15:57.697220 | controller | Uninstalling setuptools-62.6.0: 2025-12-01 00:15:57.705338 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-01 00:15:58.084471 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-01 00:15:58.214830 | controller | 2025-12-01 00:15:58.299449 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-01 00:15:58.299496 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-01 00:15:58.467621 | controller | ok: Runtime: 0:00:02.180385 2025-12-01 00:15:58.480321 | 2025-12-01 00:15:58.480521 | TASK [Install pytest-forked into virtualenv] 2025-12-01 00:15:59.077803 | controller | Collecting pytest-forked 2025-12-01 00:15:59.120339 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-01 00:15:59.159728 | controller | Collecting py 2025-12-01 00:15:59.171727 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-01 00:15:59.192767 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00 2025-12-01 00:15:59.292199 | controller | Collecting pytest>=3.10 2025-12-01 00:15:59.295781 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-12-01 00:15:59.326020 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 28.7 MB/s eta 0:00:00 2025-12-01 00:15:59.371405 | controller | Collecting iniconfig>=1.0.1 2025-12-01 00:15:59.374750 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-01 00:15:59.411339 | controller | Collecting packaging>=22 2025-12-01 00:15:59.414655 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-01 00:15:59.420795 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 13.2 MB/s eta 0:00:00 2025-12-01 00:15:59.450276 | controller | Collecting pluggy<2,>=1.5 2025-12-01 00:15:59.453396 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-01 00:15:59.503819 | controller | Collecting pygments>=2.7.2 2025-12-01 00:15:59.507622 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-01 00:15:59.527515 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 69.2 MB/s eta 0:00:00 2025-12-01 00:15:59.597009 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-01 00:16:30.792725 | [Zuul] Log Stream did not terminate 2025-12-01 00:16:30.793066 | controller | ok: Runtime: 0:00:02.061816 2025-12-01 00:16:30.805356 | 2025-12-01 00:16:30.805477 | TASK [Update pip] 2025-12-01 00:20:50.997451 | controller | ERROR 2025-12-01 00:20:50.997684 | controller | { 2025-12-01 00:20:50.997724 | controller | "msg": "Data could not be sent to remote host \"162.253.55.186\". Make sure this host can be reached over ssh: ssh: connect to host 162.253.55.186 port 22: No route to host\r\n", 2025-12-01 00:20:50.997760 | controller | "unreachable": true 2025-12-01 00:20:50.997786 | controller | } unreachable 2025-12-01 00:20:50.999872 | 2025-12-01 00:20:50.999928 | PLAY RECAP 2025-12-01 00:20:50.999981 | controller | ok: 16 changed: 8 unreachable: 1 failed: 0 skipped: 4 rescued: 0 ignored: 0 2025-12-01 00:20:51.000011 | 2025-12-01 00:20:51.133823 | PRE-RUN END RESULT_UNREACHABLE: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-01 00:20:51.135284 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 00:20:51.723265 | 2025-12-01 00:20:51.723379 | PLAY [all] 2025-12-01 00:20:51.744809 | 2025-12-01 00:20:51.744905 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-01 00:21:02.145073 | controller | changed: non-zero return code 2025-12-01 00:21:02.159437 | 2025-12-01 00:21:02.159612 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-01 00:21:02.186523 | controller | skipping: Conditional result was False 2025-12-01 00:21:02.196503 | 2025-12-01 00:21:02.196646 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-01 00:21:02.241327 | 2025-12-01 00:21:02.241562 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-01 00:21:02.275377 | 2025-12-01 00:21:02.275571 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-01 00:21:02.300109 | controller | skipping: Conditional result was False 2025-12-01 00:21:02.309717 | 2025-12-01 00:21:02.309815 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-01 00:21:02.345769 | 2025-12-01 00:21:02.345964 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-01 00:21:02.370396 | controller | skipping: Conditional result was False 2025-12-01 00:21:02.390469 | 2025-12-01 00:21:02.390675 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-01 00:21:02.416000 | controller | skipping: Conditional result was False 2025-12-01 00:21:02.426981 | 2025-12-01 00:21:02.427189 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-01 00:21:02.453454 | controller | skipping: Conditional result was False 2025-12-01 00:21:02.510786 | 2025-12-01 00:21:02.510944 | PLAY RECAP 2025-12-01 00:21:02.511049 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-01 00:21:02.511132 | 2025-12-01 00:21:02.621596 | POST-RUN END RESULT_UNREACHABLE: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 00:21:02.622702 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-01 00:21:03.172487 | 2025-12-01 00:21:03.172625 | PLAY [all:!appliance*] 2025-12-01 00:21:03.199169 | 2025-12-01 00:21:03.199290 | TASK [unregister the node] 2025-12-01 00:21:03.731146 | controller | skipping: Conditional result was False 2025-12-01 00:21:03.744602 | 2025-12-01 00:21:03.744794 | TASK [include_role : fetch-output] 2025-12-01 00:21:03.789811 | controller | ok 2025-12-01 00:21:03.819243 | 2025-12-01 00:21:03.819387 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-01 00:21:03.874490 | controller | skipping: Conditional result was False 2025-12-01 00:21:03.885105 | 2025-12-01 00:21:03.885300 | TASK [fetch-output : Set log path for single node] 2025-12-01 00:21:03.933121 | controller | ok 2025-12-01 00:21:03.946936 | 2025-12-01 00:21:03.947064 | LOOP [fetch-output : Ensure local output dirs] 2025-12-01 00:21:04.435194 | controller -> localhost | ok: "/var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/logs" 2025-12-01 00:21:04.683204 | controller -> localhost | changed: "/var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/artifacts" 2025-12-01 00:21:04.901661 | controller -> localhost | changed: "/var/lib/zuul/builds/ac48566651d04a6c9b119d2b72614100/work/docs" 2025-12-01 00:21:04.918901 | 2025-12-01 00:21:04.919012 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-01 00:21:05.599802 | controller | changed: 2025-12-01 00:21:05.600059 | controller | .d..t...... ./ 2025-12-01 00:21:05.600103 | controller | cd+++++++++ controller/ 2025-12-01 00:21:05.600146 | controller | changed: All items complete 2025-12-01 00:21:05.600175 | 2025-12-01 00:21:06.128187 | controller | changed: .d..t...... ./ 2025-12-01 00:21:06.674453 | controller | changed: .d..t...... ./ 2025-12-01 00:21:06.695707 | 2025-12-01 00:21:06.695839 | TASK [include_role : fetch-output-openshift] 2025-12-01 00:21:06.711364 | controller | skipping: Conditional result was False 2025-12-01 00:21:06.723289 | 2025-12-01 00:21:06.723459 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-01 00:21:06.759106 | controller | skipping: Conditional result was False 2025-12-01 00:21:06.774400 | controller | skipping: Conditional result was False 2025-12-01 00:21:06.812711 | 2025-12-01 00:21:06.812858 | PLAY [localhost] 2025-12-01 00:21:06.826828 | 2025-12-01 00:21:06.826957 | TASK [Run Zuul manifest role] 2025-12-01 00:21:06.845609 | localhost | ok 2025-12-01 00:21:06.861336 | 2025-12-01 00:21:06.861443 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-01 00:21:07.280161 | localhost | changed 2025-12-01 00:21:07.284958 | 2025-12-01 00:21:07.285063 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-01 00:21:07.322985 | localhost | ok 2025-12-01 00:21:07.341116 | 2025-12-01 00:21:07.341258 | TASK [Set zuul-log-path fact] 2025-12-01 00:21:07.363372 | localhost | ok 2025-12-01 00:21:07.385614 | 2025-12-01 00:21:07.385763 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 00:21:07.416506 | localhost | ok 2025-12-01 00:21:07.426318 | 2025-12-01 00:21:07.426432 | LOOP [Run upload-logs-swift role] 2025-12-01 00:21:07.461397 | localhost | Output suppressed because no_log was given 2025-12-01 00:21:07.488810 | 2025-12-01 00:21:07.488929 | TASK [Set zuul-log-path fact] 2025-12-01 00:21:07.513509 | localhost | skipping: Conditional result was False 2025-12-01 00:21:07.518914 | 2025-12-01 00:21:07.519029 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-01 00:21:07.934146 | localhost -> localhost | ok: Runtime: 0:00:00.005428 2025-12-01 00:21:07.978950 | 2025-12-01 00:21:07.979092 | TASK [upload-logs-swift : Upload logs to swift]