2026-01-14 00:07:03.064666 | Job console starting... 2026-01-14 00:07:03.074414 | Updating repositories 2026-01-14 00:07:03.188582 | Preparing job workspace 2026-01-14 00:07:07.110944 | Running Ansible setup... 2026-01-14 00:07:13.152848 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-14 00:07:16.007649 | 2026-01-14 00:07:16.007811 | PLAY [localhost] 2026-01-14 00:07:16.021644 | 2026-01-14 00:07:16.021784 | TASK [Gathering Facts] 2026-01-14 00:07:16.988631 | localhost | ok 2026-01-14 00:07:17.022848 | 2026-01-14 00:07:17.023023 | TASK [Setup log path fact] 2026-01-14 00:07:17.045217 | localhost | ok 2026-01-14 00:07:17.067013 | 2026-01-14 00:07:17.067179 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-14 00:07:17.105820 | localhost | ok 2026-01-14 00:07:17.124329 | 2026-01-14 00:07:17.124438 | TASK [emit-job-header : Print job information] 2026-01-14 00:07:17.162807 | # Job Information 2026-01-14 00:07:17.162954 | Ansible Version: 2.15.12 2026-01-14 00:07:17.162985 | Job: ansible-test-sanity-docker-devel 2026-01-14 00:07:17.163005 | Pipeline: periodic 2026-01-14 00:07:17.163023 | Executor: ze03.softwarefactory-project.io 2026-01-14 00:07:17.163040 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-14 00:07:17.163060 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/850/ansible/85086c6830084f9188d1bdd98ce76777/ 2026-01-14 00:07:17.163078 | Event ID: 6a8911388478401588366a6209bb2579 2026-01-14 00:07:17.167050 | 2026-01-14 00:07:17.167126 | LOOP [emit-job-header : Print node information] 2026-01-14 00:07:17.259616 | localhost | ok: 2026-01-14 00:07:17.259823 | localhost | # Node Information 2026-01-14 00:07:17.259852 | localhost | Inventory Hostname: controller 2026-01-14 00:07:17.259872 | localhost | Hostname: np0005583406 2026-01-14 00:07:17.259892 | localhost | Username: zuul 2026-01-14 00:07:17.259918 | localhost | Distro: Fedora 37 2026-01-14 00:07:17.259938 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-14 00:07:17.259957 | localhost | Region: ca-ymq-1 2026-01-14 00:07:17.259974 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-14 00:07:17.259992 | localhost | Product Name: OpenStack Nova 2026-01-14 00:07:17.260009 | localhost | Interface IP: 162.253.55.250 2026-01-14 00:07:17.293327 | 2026-01-14 00:07:17.293545 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-14 00:07:17.725376 | localhost -> localhost | changed 2026-01-14 00:07:17.731296 | 2026-01-14 00:07:17.731401 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-14 00:07:18.627705 | localhost -> localhost | changed 2026-01-14 00:07:18.662929 | 2026-01-14 00:07:18.663060 | PLAY [all:!appliance*] 2026-01-14 00:07:18.695609 | 2026-01-14 00:07:18.695754 | TASK [include_role : start-zuul-console] 2026-01-14 00:07:18.714994 | controller | ok 2026-01-14 00:07:18.728995 | 2026-01-14 00:07:18.729098 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-14 00:07:19.097067 | controller | ok 2026-01-14 00:07:19.113820 | 2026-01-14 00:07:19.113970 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-14 00:07:19.916325 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-14 00:07:19.926758 | 2026-01-14 00:07:19.926871 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-14 00:07:20.999324 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.006083 | 2026-01-14 00:07:21.006217 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-14 00:07:21.034204 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.042891 | 2026-01-14 00:07:21.043038 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-14 00:07:21.068345 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.074862 | 2026-01-14 00:07:21.074985 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-14 00:07:21.089277 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.096758 | 2026-01-14 00:07:21.096889 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-14 00:07:21.113255 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.120354 | 2026-01-14 00:07:21.120487 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-14 00:07:21.134747 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.148228 | 2026-01-14 00:07:21.148414 | TASK [Disable Fedora Modular] 2026-01-14 00:07:21.500492 | controller | changed 2026-01-14 00:07:21.514442 | 2026-01-14 00:07:21.514708 | TASK [Enable EPEL] 2026-01-14 00:07:21.542452 | controller | skipping: Conditional result was False 2026-01-14 00:07:21.553025 | 2026-01-14 00:07:21.553189 | TASK [Register the RHEL node] 2026-01-14 00:07:22.107433 | 2026-01-14 00:07:22.107634 | TASK [Show the subscription-manager status] 2026-01-14 00:07:22.692474 | controller | skipping: Conditional result was False 2026-01-14 00:07:22.698967 | 2026-01-14 00:07:22.699060 | TASK [Enable EPEL on RHEL] 2026-01-14 00:07:23.233518 | controller | skipping: Conditional result was False 2026-01-14 00:07:23.249383 | 2026-01-14 00:07:23.249838 | TASK [Install git and tox] 2026-01-14 00:09:07.975406 | controller | changed 2026-01-14 00:09:07.991303 | 2026-01-14 00:09:07.991432 | TASK [include_role : prepare-workspace] 2026-01-14 00:09:08.012047 | controller | ok 2026-01-14 00:09:08.034118 | 2026-01-14 00:09:08.034217 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-14 00:09:08.279570 | controller | ok 2026-01-14 00:09:08.292982 | 2026-01-14 00:09:08.293118 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-14 00:09:21.633529 | controller | Output suppressed because no_log was given 2026-01-14 00:09:21.677228 | 2026-01-14 00:09:21.677346 | TASK [include_role : prepare-workspace-openshift] 2026-01-14 00:09:21.694358 | controller | skipping: Conditional result was False 2026-01-14 00:09:21.723979 | 2026-01-14 00:09:21.724084 | PLAY [all:!appliance] 2026-01-14 00:09:21.741987 | 2026-01-14 00:09:21.742098 | TASK [Run add-build-sshkey role (RSA)] 2026-01-14 00:09:21.773911 | controller | ok 2026-01-14 00:09:21.794760 | 2026-01-14 00:09:21.794854 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-14 00:09:22.014842 | controller -> localhost | ok 2026-01-14 00:09:22.023330 | 2026-01-14 00:09:22.023471 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-14 00:09:22.060541 | controller | ok 2026-01-14 00:09:22.074689 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-14 00:09:22.081610 | 2026-01-14 00:09:22.081686 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-14 00:09:22.563649 | controller -> localhost | Generating public/private rsa key pair. 2026-01-14 00:09:22.563938 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_rsa. 2026-01-14 00:09:22.563984 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_rsa.pub. 2026-01-14 00:09:22.564041 | controller -> localhost | The key fingerprint is: 2026-01-14 00:09:22.564071 | controller -> localhost | SHA256:32TKEkvyklQh/JB28lpbn80CP/C4y7AZj4sLQLtE+LA zuul-build-sshkey 2026-01-14 00:09:22.564101 | controller -> localhost | The key's randomart image is: 2026-01-14 00:09:22.564130 | controller -> localhost | +---[RSA 2048]----+ 2026-01-14 00:09:22.564158 | controller -> localhost | | .... | 2026-01-14 00:09:22.564187 | controller -> localhost | | . *... | 2026-01-14 00:09:22.564212 | controller -> localhost | |o o . *. | 2026-01-14 00:09:22.564240 | controller -> localhost | | * . .+ + | 2026-01-14 00:09:22.564268 | controller -> localhost | |E = ooSo Bo+ | 2026-01-14 00:09:22.564314 | controller -> localhost | | . o ..=.=.=B o | 2026-01-14 00:09:22.564351 | controller -> localhost | | . . o * +..o | 2026-01-14 00:09:22.564382 | controller -> localhost | | . o X. | 2026-01-14 00:09:22.564409 | controller -> localhost | | o.=.+. | 2026-01-14 00:09:22.564437 | controller -> localhost | +----[SHA256]-----+ 2026-01-14 00:09:22.564499 | controller -> localhost | ok: Runtime: 0:00:00.099526 2026-01-14 00:09:22.573444 | 2026-01-14 00:09:22.573523 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-14 00:09:22.595109 | controller | ok 2026-01-14 00:09:22.607376 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-14 00:09:22.619265 | 2026-01-14 00:09:22.619368 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-14 00:09:22.633334 | controller | skipping: Conditional result was False 2026-01-14 00:09:22.642015 | 2026-01-14 00:09:22.642174 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-14 00:09:23.065517 | controller | changed 2026-01-14 00:09:23.072968 | 2026-01-14 00:09:23.073043 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-14 00:09:23.298399 | controller | ok 2026-01-14 00:09:23.309650 | 2026-01-14 00:09:23.309784 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-14 00:09:23.933556 | controller | changed 2026-01-14 00:09:23.948549 | 2026-01-14 00:09:23.948666 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-14 00:09:24.562046 | controller | changed 2026-01-14 00:09:24.568116 | 2026-01-14 00:09:24.568190 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-14 00:09:24.592561 | controller | skipping: Conditional result was False 2026-01-14 00:09:24.599249 | 2026-01-14 00:09:24.599326 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-14 00:09:25.035231 | controller -> localhost | changed 2026-01-14 00:09:25.052574 | 2026-01-14 00:09:25.052673 | TASK [add-build-sshkey : Add back temp key] 2026-01-14 00:09:25.386699 | controller -> localhost | Identity added: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_rsa (zuul-build-sshkey) 2026-01-14 00:09:25.386970 | controller -> localhost | ok: Runtime: 0:00:00.013568 2026-01-14 00:09:25.397457 | 2026-01-14 00:09:25.397603 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-14 00:09:25.742100 | controller | ok 2026-01-14 00:09:25.754126 | 2026-01-14 00:09:25.754287 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-14 00:09:25.779759 | controller | skipping: Conditional result was False 2026-01-14 00:09:25.795532 | 2026-01-14 00:09:25.795642 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-14 00:09:25.819933 | controller | ok 2026-01-14 00:09:25.840907 | 2026-01-14 00:09:25.841010 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-14 00:09:26.131293 | controller -> localhost | ok 2026-01-14 00:09:26.141081 | 2026-01-14 00:09:26.141195 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-14 00:09:26.175696 | controller | ok 2026-01-14 00:09:26.191332 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-14 00:09:26.201175 | 2026-01-14 00:09:26.201267 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-14 00:09:26.501394 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-14 00:09:26.501692 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_ecdsa. 2026-01-14 00:09:26.501759 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_ecdsa.pub. 2026-01-14 00:09:26.501807 | controller -> localhost | The key fingerprint is: 2026-01-14 00:09:26.501840 | controller -> localhost | SHA256:xs5L/S3CSdsyyR0w7OFaNp7lalFWl20AnpKFLJH1Qm4 zuul-build-sshkey 2026-01-14 00:09:26.501872 | controller -> localhost | The key's randomart image is: 2026-01-14 00:09:26.501902 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-14 00:09:26.501932 | controller -> localhost | | .=o.o...o| 2026-01-14 00:09:26.501961 | controller -> localhost | | ooo= ...+| 2026-01-14 00:09:26.501990 | controller -> localhost | | oE +. o | 2026-01-14 00:09:26.502018 | controller -> localhost | | . .=oo | 2026-01-14 00:09:26.502046 | controller -> localhost | | So * | 2026-01-14 00:09:26.502075 | controller -> localhost | | + .O o | 2026-01-14 00:09:26.502102 | controller -> localhost | | +O.% . | 2026-01-14 00:09:26.502128 | controller -> localhost | | ...&.=. | 2026-01-14 00:09:26.502157 | controller -> localhost | | ...=... | 2026-01-14 00:09:26.502186 | controller -> localhost | +----[SHA256]-----+ 2026-01-14 00:09:26.502251 | controller -> localhost | ok: Runtime: 0:00:00.011336 2026-01-14 00:09:26.516926 | 2026-01-14 00:09:26.517151 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-14 00:09:26.541607 | controller | ok 2026-01-14 00:09:26.549650 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-14 00:09:26.559588 | 2026-01-14 00:09:26.559717 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-14 00:09:26.584454 | controller | skipping: Conditional result was False 2026-01-14 00:09:26.592682 | 2026-01-14 00:09:26.592843 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-14 00:09:26.860983 | controller | changed 2026-01-14 00:09:26.871010 | 2026-01-14 00:09:26.871141 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-14 00:09:27.080456 | controller | ok 2026-01-14 00:09:27.090314 | 2026-01-14 00:09:27.090462 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-14 00:09:27.723542 | controller | changed 2026-01-14 00:09:27.730427 | 2026-01-14 00:09:27.730542 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-14 00:09:28.372994 | controller | changed 2026-01-14 00:09:28.386416 | 2026-01-14 00:09:28.386573 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-14 00:09:28.414025 | controller | skipping: Conditional result was False 2026-01-14 00:09:28.424569 | 2026-01-14 00:09:28.424752 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-14 00:09:28.697143 | controller -> localhost | changed 2026-01-14 00:09:28.738742 | 2026-01-14 00:09:28.738863 | TASK [add-build-sshkey : Add back temp key] 2026-01-14 00:09:29.010171 | controller -> localhost | Identity added: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/85086c6830084f9188d1bdd98ce76777_id_ecdsa (zuul-build-sshkey) 2026-01-14 00:09:29.010436 | controller -> localhost | ok: Runtime: 0:00:00.011373 2026-01-14 00:09:29.017525 | 2026-01-14 00:09:29.017593 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-14 00:09:29.228687 | controller | ok 2026-01-14 00:09:29.239749 | 2026-01-14 00:09:29.239869 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-14 00:09:29.275866 | controller | skipping: Conditional result was False 2026-01-14 00:09:29.292862 | 2026-01-14 00:09:29.292969 | TASK [include_role : remove-zuul-sshkey] 2026-01-14 00:09:29.319052 | controller | skipping: Conditional result was False 2026-01-14 00:09:29.328355 | 2026-01-14 00:09:29.328458 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-14 00:09:29.564748 | controller | ok: "logs" 2026-01-14 00:09:29.565010 | controller | ok: All items complete 2026-01-14 00:09:29.565039 | 2026-01-14 00:09:29.759041 | controller | ok: "artifacts" 2026-01-14 00:09:29.962577 | controller | ok: "docs" 2026-01-14 00:09:29.980625 | 2026-01-14 00:09:29.980777 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-14 00:09:30.231930 | controller | changed: "logs" 2026-01-14 00:09:30.435850 | controller | changed: "artifacts" 2026-01-14 00:09:30.633498 | controller | changed: "docs" 2026-01-14 00:09:30.681076 | 2026-01-14 00:09:30.681199 | PLAY RECAP 2026-01-14 00:09:30.681258 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-14 00:09:30.681295 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-14 00:09:30.681322 | 2026-01-14 00:09:30.801572 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-14 00:09:30.802860 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-14 00:09:31.485279 | 2026-01-14 00:09:31.485422 | PLAY [all] 2026-01-14 00:09:31.508685 | 2026-01-14 00:09:31.508944 | TASK [Install binary dependencies] 2026-01-14 00:09:31.560219 | controller | ok 2026-01-14 00:09:31.583704 | 2026-01-14 00:09:31.583867 | TASK [bindep : Include find tasks] 2026-01-14 00:09:31.613136 | controller | ok 2026-01-14 00:09:31.620990 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-14 00:09:31.627763 | 2026-01-14 00:09:31.627846 | TASK [bindep : Look for bindep.txt] 2026-01-14 00:09:31.984507 | controller | ok 2026-01-14 00:09:31.990489 | 2026-01-14 00:09:31.990601 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:09:32.005041 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.014179 | 2026-01-14 00:09:32.014277 | TASK [bindep : Look for other-requirements.txt] 2026-01-14 00:09:32.228117 | controller | ok 2026-01-14 00:09:32.242615 | 2026-01-14 00:09:32.242858 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:09:32.271824 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.290406 | 2026-01-14 00:09:32.290637 | TASK [bindep : Look for bindep fallback file] 2026-01-14 00:09:32.333219 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.348915 | 2026-01-14 00:09:32.349099 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:09:32.375615 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.386037 | 2026-01-14 00:09:32.386164 | TASK [bindep : Include bindep tasks] 2026-01-14 00:09:32.412506 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.422805 | 2026-01-14 00:09:32.422955 | TASK [bindep : Include install tasks] 2026-01-14 00:09:32.447336 | controller | skipping: Conditional result was False 2026-01-14 00:09:32.462874 | 2026-01-14 00:09:32.463059 | LOOP [bindep : Include package tasks] 2026-01-14 00:09:32.520976 | 2026-01-14 00:09:32.521188 | TASK [Run test-setup role] 2026-01-14 00:09:32.545993 | controller | ok 2026-01-14 00:09:32.570225 | 2026-01-14 00:09:32.570353 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-14 00:09:32.786580 | controller | ok 2026-01-14 00:09:32.805627 | 2026-01-14 00:09:32.805846 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-14 00:09:33.348450 | controller | skipping: Conditional result was False 2026-01-14 00:09:33.388612 | 2026-01-14 00:09:33.388746 | PLAY RECAP 2026-01-14 00:09:33.388807 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-14 00:09:33.388836 | 2026-01-14 00:09:33.492260 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-14 00:09:33.493231 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-14 00:09:34.128650 | 2026-01-14 00:09:34.128816 | PLAY [controller] 2026-01-14 00:09:34.150273 | 2026-01-14 00:09:34.150436 | TASK [Create the /root directory] 2026-01-14 00:09:34.521168 | controller | ok 2026-01-14 00:09:34.529596 | 2026-01-14 00:09:34.529711 | TASK [Install glibc-langpack-en] 2026-01-14 00:09:38.532875 | controller | ok: Nothing to do 2026-01-14 00:09:38.542514 | 2026-01-14 00:09:38.542628 | TASK [Ensure controller directory exists] 2026-01-14 00:09:38.762736 | controller | changed 2026-01-14 00:09:38.771907 | 2026-01-14 00:09:38.772004 | TASK [Install container runtime] 2026-01-14 00:09:38.830162 | controller | ok 2026-01-14 00:09:38.883097 | 2026-01-14 00:09:38.883217 | LOOP [ensure-podman : Find distribution installation] 2026-01-14 00:09:38.921265 | controller | ok: "/var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-14 00:09:38.936366 | controller | included: /var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-14 00:09:38.945909 | 2026-01-14 00:09:38.946045 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-14 00:10:44.835434 | controller | changed 2026-01-14 00:10:44.845867 | 2026-01-14 00:10:44.845997 | TASK [ensure-podman : Fetch podman version] 2026-01-14 00:10:45.368500 | controller | Client: Podman Engine 2026-01-14 00:10:45.368603 | controller | Version: 4.6.2 2026-01-14 00:10:45.368671 | controller | API Version: 4.6.2 2026-01-14 00:10:45.368738 | controller | Go Version: go1.19.12 2026-01-14 00:10:45.368797 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-14 00:10:45.368843 | controller | OS/Arch: linux/amd64 2026-01-14 00:10:45.881437 | controller | ok: Runtime: 0:00:00.184846 2026-01-14 00:10:45.895904 | 2026-01-14 00:10:45.896078 | TASK [ensure-podman : Print podman version installed] 2026-01-14 00:10:45.939668 | Podman version: Client: Podman Engine 2026-01-14 00:10:45.940145 | Version: 4.6.2 2026-01-14 00:10:45.940226 | API Version: 4.6.2 2026-01-14 00:10:45.940276 | Go Version: go1.19.12 2026-01-14 00:10:45.940320 | Built: Mon Aug 28 19:38:31 2023 2026-01-14 00:10:45.940365 | OS/Arch: linux/amd64 2026-01-14 00:10:45.954040 | 2026-01-14 00:10:45.954188 | TASK [ensure-podman : Validate podman engine] 2026-01-14 00:10:46.503692 | controller | skipping: Conditional result was False 2026-01-14 00:10:46.510621 | 2026-01-14 00:10:46.510719 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-14 00:10:46.526257 | controller | skipping: Conditional result was False 2026-01-14 00:10:46.538711 | 2026-01-14 00:10:46.538866 | TASK [Ensure python3.8 is present] 2026-01-14 00:10:46.553470 | controller | skipping: Conditional result was False 2026-01-14 00:10:46.560876 | 2026-01-14 00:10:46.560994 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-14 00:10:46.583360 | controller | ok 2026-01-14 00:10:46.603615 | 2026-01-14 00:10:46.603761 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-14 00:10:47.906825 | controller | ok: Nothing to do 2026-01-14 00:10:47.913400 | 2026-01-14 00:10:47.913484 | TASK [our-ensure-python : Also install python3-devel] 2026-01-14 00:10:57.766921 | controller | changed 2026-01-14 00:10:57.792514 | 2026-01-14 00:10:57.792753 | TASK [Run ensure-virtualenv role] 2026-01-14 00:10:57.818541 | controller | ok 2026-01-14 00:10:57.849673 | 2026-01-14 00:10:57.849844 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-14 00:10:58.894176 | controller | /usr/bin/virtualenv 2026-01-14 00:11:00.177120 | controller | ok: Runtime: 0:00:00.004735 2026-01-14 00:11:00.183514 | 2026-01-14 00:11:00.183586 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-14 00:11:00.207621 | controller | skipping: Conditional result was False 2026-01-14 00:11:00.208018 | controller | ok: All items complete 2026-01-14 00:11:00.208055 | 2026-01-14 00:11:00.237125 | 2026-01-14 00:11:00.237324 | TASK [Find the full path of the Python interpreter] 2026-01-14 00:11:00.512474 | controller | /usr/bin/python3 2026-01-14 00:11:01.089464 | controller | ok 2026-01-14 00:11:01.097539 | 2026-01-14 00:11:01.097648 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-14 00:11:03.451770 | controller | created virtual environment CPython3.11.0.final.0-64 in 482ms 2026-01-14 00:11:03.467833 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-14 00:11:03.467872 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-01-14 00:11:03.467881 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-14 00:11:03.467895 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-14 00:11:03.704654 | controller | changed 2026-01-14 00:11:03.710983 | 2026-01-14 00:11:03.711050 | TASK [Set selinux package] 2026-01-14 00:11:03.730754 | controller | ok 2026-01-14 00:11:03.735997 | 2026-01-14 00:11:03.736060 | TASK [Set selinux package (Fedora)] 2026-01-14 00:11:03.764784 | controller | ok 2026-01-14 00:11:03.769916 | 2026-01-14 00:11:03.769976 | TASK [Install selinux into virtualenv] 2026-01-14 00:11:17.338507 | controller | Collecting selinux-please-lie-to-me 2026-01-14 00:11:29.605828 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-14 00:11:29.925786 | controller | Collecting setuptools<50.0.0 2026-01-14 00:11:29.954428 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-14 00:11:29.994395 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.5 MB/s eta 0:00:00 2026-01-14 00:11:30.075268 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-14 00:11:30.075435 | controller | Attempting uninstall: setuptools 2026-01-14 00:11:30.077762 | controller | Found existing installation: setuptools 62.6.0 2026-01-14 00:11:30.136568 | controller | Uninstalling setuptools-62.6.0: 2026-01-14 00:11:30.144241 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-14 00:11:30.504970 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-14 00:11:41.976059 | controller | 2026-01-14 00:11:42.052617 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-14 00:11:42.052658 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-14 00:11:42.398345 | controller | ok: Runtime: 0:00:38.043554 2026-01-14 00:11:42.404742 | 2026-01-14 00:11:42.404806 | TASK [Install pytest-forked into virtualenv] 2026-01-14 00:11:54.232866 | controller | Collecting pytest-forked 2026-01-14 00:12:06.466785 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-14 00:12:06.529884 | controller | Collecting py 2026-01-14 00:12:06.560867 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-14 00:12:06.584785 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.5 MB/s eta 0:00:00 2026-01-14 00:12:06.726529 | controller | Collecting pytest>=3.10 2026-01-14 00:12:06.735704 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-14 00:12:06.748437 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 37.7 MB/s eta 0:00:00 2026-01-14 00:12:06.813202 | controller | Collecting iniconfig>=1.0.1 2026-01-14 00:12:06.816792 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-14 00:12:06.862505 | controller | Collecting packaging>=22 2026-01-14 00:12:06.865785 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-14 00:12:06.873215 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.5 MB/s eta 0:00:00 2026-01-14 00:12:06.910059 | controller | Collecting pluggy<2,>=1.5 2026-01-14 00:12:06.913290 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-14 00:12:06.972269 | controller | Collecting pygments>=2.7.2 2026-01-14 00:12:06.979247 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-14 00:12:06.999349 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 69.1 MB/s eta 0:00:00 2026-01-14 00:12:07.068065 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-14 00:12:08.074083 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-01-14 00:12:08.082619 | controller | 2026-01-14 00:12:08.148419 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-14 00:12:08.148461 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-14 00:12:08.459066 | controller | ok: Runtime: 0:00:25.514340 2026-01-14 00:12:08.474637 | 2026-01-14 00:12:08.474870 | TASK [Update pip] 2026-01-14 00:12:09.016407 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-14 00:12:18.838024 | controller | Collecting pip 2026-01-14 00:12:31.032365 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-14 00:12:31.098774 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 28.8 MB/s eta 0:00:00 2026-01-14 00:12:31.162642 | controller | Installing collected packages: pip 2026-01-14 00:12:31.162794 | controller | Attempting uninstall: pip 2026-01-14 00:12:31.165185 | controller | Found existing installation: pip 22.2.2 2026-01-14 00:12:31.304000 | controller | Uninstalling pip-22.2.2: 2026-01-14 00:12:31.319048 | controller | Successfully uninstalled pip-22.2.2 2026-01-14 00:12:32.120211 | controller | Successfully installed pip-25.3 2026-01-14 00:12:32.541015 | controller | ok: Runtime: 0:00:23.482705 2026-01-14 00:12:32.549067 | 2026-01-14 00:12:32.549157 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-14 00:12:32.793406 | controller | changed 2026-01-14 00:12:32.807507 | 2026-01-14 00:12:32.808260 | TASK [Install ansible into virtualenv] 2026-01-14 00:12:33.319919 | controller | Processing ./src/github.com/ansible/ansible 2026-01-14 00:12:33.323263 | controller | Installing build dependencies: started 2026-01-14 00:12:56.183151 | controller | Installing build dependencies: finished with status 'done' 2026-01-14 00:12:56.183777 | controller | Getting requirements to build wheel: started 2026-01-14 00:12:56.925377 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-14 00:12:56.927100 | controller | Preparing metadata (pyproject.toml): started 2026-01-14 00:12:57.401819 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-14 00:12:57.404508 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-01-14 00:12:57.406983 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-14 00:12:57.869891 | controller | ERROR 2026-01-14 00:12:57.870296 | controller | { 2026-01-14 00:12:57.870360 | controller | "delta": "0:00:24.429125", 2026-01-14 00:12:57.870403 | controller | "end": "2026-01-14 00:12:57.467217", 2026-01-14 00:12:57.870444 | controller | "msg": "non-zero return code", 2026-01-14 00:12:57.870567 | controller | "rc": 1, 2026-01-14 00:12:57.870611 | controller | "start": "2026-01-14 00:12:33.038092" 2026-01-14 00:12:57.870647 | controller | } failure 2026-01-14 00:12:57.874216 | 2026-01-14 00:12:57.874318 | PLAY RECAP 2026-01-14 00:12:57.874418 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-14 00:12:57.874516 | 2026-01-14 00:12:58.076280 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-14 00:12:58.077268 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-14 00:12:58.657372 | 2026-01-14 00:12:58.657491 | PLAY [all] 2026-01-14 00:12:58.679186 | 2026-01-14 00:12:58.679307 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-14 00:12:58.912344 | controller | changed: non-zero return code 2026-01-14 00:12:58.918379 | 2026-01-14 00:12:58.918466 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-14 00:12:58.932288 | controller | skipping: Conditional result was False 2026-01-14 00:12:58.938979 | 2026-01-14 00:12:58.939073 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-14 00:12:58.972598 | 2026-01-14 00:12:58.972808 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-14 00:12:58.995808 | 2026-01-14 00:12:58.996000 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-14 00:12:59.010413 | controller | skipping: Conditional result was False 2026-01-14 00:12:59.021978 | 2026-01-14 00:12:59.022143 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-14 00:12:59.050377 | 2026-01-14 00:12:59.050620 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-14 00:12:59.067481 | controller | skipping: Conditional result was False 2026-01-14 00:12:59.080234 | 2026-01-14 00:12:59.080402 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-14 00:12:59.097121 | controller | skipping: Conditional result was False 2026-01-14 00:12:59.110894 | 2026-01-14 00:12:59.111069 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-14 00:12:59.127428 | controller | skipping: Conditional result was False 2026-01-14 00:12:59.169654 | 2026-01-14 00:12:59.169800 | PLAY RECAP 2026-01-14 00:12:59.169856 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-14 00:12:59.169888 | 2026-01-14 00:12:59.270889 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-14 00:12:59.271995 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-14 00:12:59.839290 | 2026-01-14 00:12:59.839405 | PLAY [all:!appliance*] 2026-01-14 00:12:59.862662 | 2026-01-14 00:12:59.862804 | TASK [unregister the node] 2026-01-14 00:13:00.395511 | controller | skipping: Conditional result was False 2026-01-14 00:13:00.409833 | 2026-01-14 00:13:00.410073 | TASK [include_role : fetch-output] 2026-01-14 00:13:00.459799 | controller | ok 2026-01-14 00:13:00.497245 | 2026-01-14 00:13:00.497383 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-14 00:13:00.573642 | controller | skipping: Conditional result was False 2026-01-14 00:13:00.579690 | 2026-01-14 00:13:00.579783 | TASK [fetch-output : Set log path for single node] 2026-01-14 00:13:00.619880 | controller | ok 2026-01-14 00:13:00.626117 | 2026-01-14 00:13:00.626231 | LOOP [fetch-output : Ensure local output dirs] 2026-01-14 00:13:01.016658 | controller -> localhost | ok: "/var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/logs" 2026-01-14 00:13:01.239274 | controller -> localhost | changed: "/var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/artifacts" 2026-01-14 00:13:01.512536 | controller -> localhost | changed: "/var/lib/zuul/builds/85086c6830084f9188d1bdd98ce76777/work/docs" 2026-01-14 00:13:01.529498 | 2026-01-14 00:13:01.529601 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-14 00:13:02.170240 | controller | changed: 2026-01-14 00:13:02.170569 | controller | .d..t...... ./ 2026-01-14 00:13:02.170628 | controller | cd+++++++++ controller/ 2026-01-14 00:13:02.170697 | controller | changed: All items complete 2026-01-14 00:13:02.170785 | 2026-01-14 00:13:02.639205 | controller | changed: .d..t...... ./ 2026-01-14 00:13:03.141692 | controller | changed: .d..t...... ./ 2026-01-14 00:13:03.171922 | 2026-01-14 00:13:03.172116 | TASK [include_role : fetch-output-openshift] 2026-01-14 00:13:03.200536 | controller | skipping: Conditional result was False 2026-01-14 00:13:03.215043 | 2026-01-14 00:13:03.215210 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-14 00:13:03.263322 | controller | skipping: Conditional result was False 2026-01-14 00:13:03.274330 | controller | skipping: Conditional result was False 2026-01-14 00:13:03.343354 | 2026-01-14 00:13:03.343550 | PLAY [localhost] 2026-01-14 00:13:03.361691 | 2026-01-14 00:13:03.361807 | TASK [Run Zuul manifest role] 2026-01-14 00:13:03.384552 | localhost | ok 2026-01-14 00:13:03.402608 | 2026-01-14 00:13:03.402708 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-14 00:13:03.778644 | localhost | changed 2026-01-14 00:13:03.783895 | 2026-01-14 00:13:03.783961 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-14 00:13:03.814616 | localhost | ok 2026-01-14 00:13:03.822791 | 2026-01-14 00:13:03.822853 | TASK [Set zuul-log-path fact] 2026-01-14 00:13:03.840381 | localhost | ok 2026-01-14 00:13:03.854214 | 2026-01-14 00:13:03.854317 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-14 00:13:03.893599 | localhost | ok 2026-01-14 00:13:03.901524 | 2026-01-14 00:13:03.901609 | LOOP [Run upload-logs-swift role] 2026-01-14 00:13:03.935995 | localhost | Output suppressed because no_log was given 2026-01-14 00:13:03.970703 | 2026-01-14 00:13:03.970873 | TASK [Set zuul-log-path fact] 2026-01-14 00:13:04.006099 | localhost | skipping: Conditional result was False 2026-01-14 00:13:04.013043 | 2026-01-14 00:13:04.013161 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-14 00:13:04.457256 | localhost -> localhost | ok: Runtime: 0:00:00.007355 2026-01-14 00:13:04.470309 | 2026-01-14 00:13:04.470454 | TASK [upload-logs-swift : Upload logs to swift]