2026-01-14 00:21:11.362594 | Job console starting... 2026-01-14 00:21:11.371865 | Updating repositories 2026-01-14 00:21:11.530138 | Preparing job workspace 2026-01-14 00:21:15.237941 | Running Ansible setup... 2026-01-14 00:21:23.139044 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-14 00:21:26.992256 | 2026-01-14 00:21:26.992406 | PLAY [localhost] 2026-01-14 00:21:27.002413 | 2026-01-14 00:21:27.002526 | TASK [Gathering Facts] 2026-01-14 00:21:28.042401 | localhost | ok 2026-01-14 00:21:28.071108 | 2026-01-14 00:21:28.071270 | TASK [Setup log path fact] 2026-01-14 00:21:28.092698 | localhost | ok 2026-01-14 00:21:28.111415 | 2026-01-14 00:21:28.111563 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-14 00:21:28.142436 | localhost | ok 2026-01-14 00:21:28.154006 | 2026-01-14 00:21:28.154237 | TASK [emit-job-header : Print job information] 2026-01-14 00:21:28.204607 | # Job Information 2026-01-14 00:21:28.204808 | Ansible Version: 2.15.12 2026-01-14 00:21:28.204855 | Job: ansible-test-sanity-docker-milestone 2026-01-14 00:21:28.204887 | Pipeline: periodic 2026-01-14 00:21:28.204914 | Executor: ze04.softwarefactory-project.io 2026-01-14 00:21:28.204941 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-14 00:21:28.205094 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/4c6/ansible/4c63f1aa88c2408eabbd7ad793769cde/ 2026-01-14 00:21:28.205130 | Event ID: 6a8911388478401588366a6209bb2579 2026-01-14 00:21:28.210366 | 2026-01-14 00:21:28.210454 | LOOP [emit-job-header : Print node information] 2026-01-14 00:21:28.321614 | localhost | ok: 2026-01-14 00:21:28.321976 | localhost | # Node Information 2026-01-14 00:21:28.322026 | localhost | Inventory Hostname: controller 2026-01-14 00:21:28.322059 | localhost | Hostname: np0005583431 2026-01-14 00:21:28.322154 | localhost | Username: zuul 2026-01-14 00:21:28.322196 | localhost | Distro: Fedora 37 2026-01-14 00:21:28.322227 | localhost | Provider: ansible-vexxhost-ams1 2026-01-14 00:21:28.322257 | localhost | Region: ams1 2026-01-14 00:21:28.322285 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-14 00:21:28.322314 | localhost | Product Name: OpenStack Nova 2026-01-14 00:21:28.322343 | localhost | Interface IP: 38.129.16.118 2026-01-14 00:21:28.343123 | 2026-01-14 00:21:28.343314 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-14 00:21:28.757319 | localhost -> localhost | changed 2026-01-14 00:21:28.762868 | 2026-01-14 00:21:28.762947 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-14 00:21:29.592717 | localhost -> localhost | changed 2026-01-14 00:21:29.633139 | 2026-01-14 00:21:29.633262 | PLAY [all:!appliance*] 2026-01-14 00:21:29.657576 | 2026-01-14 00:21:29.657722 | TASK [include_role : start-zuul-console] 2026-01-14 00:21:29.688835 | controller | ok 2026-01-14 00:21:29.704355 | 2026-01-14 00:21:29.704471 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-14 00:21:30.759761 | controller | ok 2026-01-14 00:21:30.773487 | 2026-01-14 00:21:30.773645 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-14 00:21:33.105515 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-14 00:21:33.124664 | 2026-01-14 00:21:33.124871 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-14 00:21:33.499824 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.510096 | 2026-01-14 00:21:33.510224 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-14 00:21:33.535403 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.542759 | 2026-01-14 00:21:33.542862 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-14 00:21:33.557412 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.565529 | 2026-01-14 00:21:33.565642 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-14 00:21:33.580141 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.588166 | 2026-01-14 00:21:33.588280 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-14 00:21:33.602365 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.610747 | 2026-01-14 00:21:33.610869 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-14 00:21:33.625582 | controller | skipping: Conditional result was False 2026-01-14 00:21:33.639623 | 2026-01-14 00:21:33.639784 | TASK [Disable Fedora Modular] 2026-01-14 00:21:34.828729 | controller | changed 2026-01-14 00:21:34.843634 | 2026-01-14 00:21:34.844182 | TASK [Enable EPEL] 2026-01-14 00:21:34.885044 | controller | skipping: Conditional result was False 2026-01-14 00:21:34.895345 | 2026-01-14 00:21:34.895442 | TASK [Register the RHEL node] 2026-01-14 00:21:35.336887 | 2026-01-14 00:21:35.337039 | TASK [Show the subscription-manager status] 2026-01-14 00:21:35.723254 | controller | skipping: Conditional result was False 2026-01-14 00:21:35.732309 | 2026-01-14 00:21:35.732444 | TASK [Enable EPEL on RHEL] 2026-01-14 00:21:36.121299 | controller | skipping: Conditional result was False 2026-01-14 00:21:36.134388 | 2026-01-14 00:21:36.134537 | TASK [Install git and tox] 2026-01-14 00:23:44.227394 | controller | changed 2026-01-14 00:23:44.243425 | 2026-01-14 00:23:44.243571 | TASK [include_role : prepare-workspace] 2026-01-14 00:23:44.277564 | controller | ok 2026-01-14 00:23:44.312232 | 2026-01-14 00:23:44.312384 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-14 00:23:45.182348 | controller | ok 2026-01-14 00:23:45.204107 | 2026-01-14 00:23:45.204297 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-14 00:24:01.102971 | controller | Output suppressed because no_log was given 2026-01-14 00:24:01.123112 | 2026-01-14 00:24:01.123215 | TASK [include_role : prepare-workspace-openshift] 2026-01-14 00:24:01.149151 | controller | skipping: Conditional result was False 2026-01-14 00:24:01.201342 | 2026-01-14 00:24:01.201443 | PLAY [all:!appliance] 2026-01-14 00:24:01.218233 | 2026-01-14 00:24:01.218341 | TASK [Run add-build-sshkey role (RSA)] 2026-01-14 00:24:01.248443 | controller | ok 2026-01-14 00:24:01.264103 | 2026-01-14 00:24:01.264184 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-14 00:24:01.565175 | controller -> localhost | ok 2026-01-14 00:24:01.580909 | 2026-01-14 00:24:01.581056 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-14 00:24:01.618180 | controller | ok 2026-01-14 00:24:01.639760 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-14 00:24:01.649461 | 2026-01-14 00:24:01.649573 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-14 00:24:02.182418 | controller -> localhost | Generating public/private rsa key pair. 2026-01-14 00:24:02.182619 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_rsa. 2026-01-14 00:24:02.182648 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_rsa.pub. 2026-01-14 00:24:02.182669 | controller -> localhost | The key fingerprint is: 2026-01-14 00:24:02.182707 | controller -> localhost | SHA256:d41c0DX2PaXEqLlLShhDFtmnNvppCtONNPbkWuMgKgI zuul-build-sshkey 2026-01-14 00:24:02.182727 | controller -> localhost | The key's randomart image is: 2026-01-14 00:24:02.182747 | controller -> localhost | +---[RSA 2048]----+ 2026-01-14 00:24:02.182768 | controller -> localhost | | .+ .+.+o| 2026-01-14 00:24:02.182786 | controller -> localhost | | + . . .o+.=| 2026-01-14 00:24:02.182804 | controller -> localhost | | o o o o.o| 2026-01-14 00:24:02.182821 | controller -> localhost | | o + o. + .| 2026-01-14 00:24:02.182838 | controller -> localhost | | +*S...+ . | 2026-01-14 00:24:02.182863 | controller -> localhost | |E +oB..o. | 2026-01-14 00:24:02.182890 | controller -> localhost | |. + +o*+ . | 2026-01-14 00:24:02.182913 | controller -> localhost | |o . + ==.. | 2026-01-14 00:24:02.182932 | controller -> localhost | |... oo. | 2026-01-14 00:24:02.182952 | controller -> localhost | +----[SHA256]-----+ 2026-01-14 00:24:02.182999 | controller -> localhost | ok: Runtime: 0:00:00.121432 2026-01-14 00:24:02.189378 | 2026-01-14 00:24:02.189442 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-14 00:24:02.221330 | controller | ok 2026-01-14 00:24:02.230935 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-14 00:24:02.239815 | 2026-01-14 00:24:02.239878 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-14 00:24:02.263950 | controller | skipping: Conditional result was False 2026-01-14 00:24:02.271020 | 2026-01-14 00:24:02.271089 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-14 00:24:03.374790 | controller | changed 2026-01-14 00:24:03.387543 | 2026-01-14 00:24:03.387763 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-14 00:24:04.076934 | controller | ok 2026-01-14 00:24:04.086046 | 2026-01-14 00:24:04.086147 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-14 00:24:07.199431 | controller | changed 2026-01-14 00:24:07.215275 | 2026-01-14 00:24:07.215448 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-14 00:24:10.302547 | controller | changed 2026-01-14 00:24:10.310872 | 2026-01-14 00:24:10.311128 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-14 00:24:10.348229 | controller | skipping: Conditional result was False 2026-01-14 00:24:10.357514 | 2026-01-14 00:24:10.357650 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-14 00:24:10.733297 | controller -> localhost | changed 2026-01-14 00:24:10.745898 | 2026-01-14 00:24:10.745989 | TASK [add-build-sshkey : Add back temp key] 2026-01-14 00:24:11.008837 | controller -> localhost | Identity added: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_rsa (zuul-build-sshkey) 2026-01-14 00:24:11.009099 | controller -> localhost | ok: Runtime: 0:00:00.008747 2026-01-14 00:24:11.018241 | 2026-01-14 00:24:11.018543 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-14 00:24:11.971237 | controller | ok 2026-01-14 00:24:11.986648 | 2026-01-14 00:24:11.986894 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-14 00:24:12.013380 | controller | skipping: Conditional result was False 2026-01-14 00:24:12.040303 | 2026-01-14 00:24:12.040435 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-14 00:24:12.072379 | controller | ok 2026-01-14 00:24:12.089149 | 2026-01-14 00:24:12.089280 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-14 00:24:12.328810 | controller -> localhost | ok 2026-01-14 00:24:12.343744 | 2026-01-14 00:24:12.343914 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-14 00:24:12.369871 | controller | ok 2026-01-14 00:24:12.385722 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-14 00:24:12.394729 | 2026-01-14 00:24:12.394823 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-14 00:24:12.715713 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-14 00:24:12.715933 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_ecdsa. 2026-01-14 00:24:12.715962 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_ecdsa.pub. 2026-01-14 00:24:12.715993 | controller -> localhost | The key fingerprint is: 2026-01-14 00:24:12.716015 | controller -> localhost | SHA256:T9zEc/qFwDF4dDA0rdGMfBsUXw/zd9miBre1EcSlZ3Q zuul-build-sshkey 2026-01-14 00:24:12.716042 | controller -> localhost | The key's randomart image is: 2026-01-14 00:24:12.716062 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-14 00:24:12.716080 | controller -> localhost | | =OXOoE| 2026-01-14 00:24:12.716100 | controller -> localhost | | .o=*BO*| 2026-01-14 00:24:12.716117 | controller -> localhost | | ..B+*+X| 2026-01-14 00:24:12.716134 | controller -> localhost | | . =.O.Bo| 2026-01-14 00:24:12.716152 | controller -> localhost | | S o * o .| 2026-01-14 00:24:12.716169 | controller -> localhost | | o . . . | 2026-01-14 00:24:12.716186 | controller -> localhost | | . . | 2026-01-14 00:24:12.716202 | controller -> localhost | | | 2026-01-14 00:24:12.716219 | controller -> localhost | | | 2026-01-14 00:24:12.716235 | controller -> localhost | +----[SHA256]-----+ 2026-01-14 00:24:12.716283 | controller -> localhost | ok: Runtime: 0:00:00.016724 2026-01-14 00:24:12.724112 | 2026-01-14 00:24:12.724186 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-14 00:24:12.755744 | controller | ok 2026-01-14 00:24:12.764775 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-14 00:24:12.774708 | 2026-01-14 00:24:12.774775 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-14 00:24:12.800194 | controller | skipping: Conditional result was False 2026-01-14 00:24:12.811012 | 2026-01-14 00:24:12.811136 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-14 00:24:13.760790 | controller | changed 2026-01-14 00:24:13.771623 | 2026-01-14 00:24:13.771837 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-14 00:24:14.435817 | controller | ok 2026-01-14 00:24:14.444492 | 2026-01-14 00:24:14.444607 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-14 00:24:17.533987 | controller | changed 2026-01-14 00:24:17.543059 | 2026-01-14 00:24:17.543154 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-14 00:24:20.624160 | controller | changed 2026-01-14 00:24:20.638238 | 2026-01-14 00:24:20.638378 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-14 00:24:20.664953 | controller | skipping: Conditional result was False 2026-01-14 00:24:20.675727 | 2026-01-14 00:24:20.675864 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-14 00:24:20.894594 | controller -> localhost | changed 2026-01-14 00:24:20.914330 | 2026-01-14 00:24:20.914451 | TASK [add-build-sshkey : Add back temp key] 2026-01-14 00:24:21.227200 | controller -> localhost | Identity added: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/4c63f1aa88c2408eabbd7ad793769cde_id_ecdsa (zuul-build-sshkey) 2026-01-14 00:24:21.227420 | controller -> localhost | ok: Runtime: 0:00:00.012915 2026-01-14 00:24:21.234018 | 2026-01-14 00:24:21.234118 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-14 00:24:21.943944 | controller | ok 2026-01-14 00:24:21.949554 | 2026-01-14 00:24:21.949618 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-14 00:24:21.993839 | controller | skipping: Conditional result was False 2026-01-14 00:24:22.013008 | 2026-01-14 00:24:22.013136 | TASK [include_role : remove-zuul-sshkey] 2026-01-14 00:24:22.038640 | controller | skipping: Conditional result was False 2026-01-14 00:24:22.046457 | 2026-01-14 00:24:22.046570 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-14 00:24:22.713348 | controller | ok: "logs" 2026-01-14 00:24:22.713848 | controller | ok: All items complete 2026-01-14 00:24:22.713915 | 2026-01-14 00:24:23.335468 | controller | ok: "artifacts" 2026-01-14 00:24:23.994244 | controller | ok: "docs" 2026-01-14 00:24:24.018493 | 2026-01-14 00:24:24.018661 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-14 00:24:24.699128 | controller | changed: "logs" 2026-01-14 00:24:25.313716 | controller | changed: "artifacts" 2026-01-14 00:24:25.977183 | controller | changed: "docs" 2026-01-14 00:24:26.030438 | 2026-01-14 00:24:26.030553 | PLAY RECAP 2026-01-14 00:24:26.030614 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-14 00:24:26.030654 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-14 00:24:26.030741 | 2026-01-14 00:24:26.147319 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-14 00:24:26.148180 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-14 00:24:26.756302 | 2026-01-14 00:24:26.756441 | PLAY [all] 2026-01-14 00:24:26.780131 | 2026-01-14 00:24:26.780249 | TASK [Install binary dependencies] 2026-01-14 00:24:26.867501 | controller | ok 2026-01-14 00:24:26.898513 | 2026-01-14 00:24:26.898666 | TASK [bindep : Include find tasks] 2026-01-14 00:24:26.948354 | controller | ok 2026-01-14 00:24:26.962752 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-14 00:24:26.971554 | 2026-01-14 00:24:26.971645 | TASK [bindep : Look for bindep.txt] 2026-01-14 00:24:27.923440 | controller | ok 2026-01-14 00:24:27.932108 | 2026-01-14 00:24:27.932200 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:24:27.947016 | controller | skipping: Conditional result was False 2026-01-14 00:24:27.955603 | 2026-01-14 00:24:27.955715 | TASK [bindep : Look for other-requirements.txt] 2026-01-14 00:24:28.599893 | controller | ok 2026-01-14 00:24:28.617258 | 2026-01-14 00:24:28.617507 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:24:28.656733 | controller | skipping: Conditional result was False 2026-01-14 00:24:28.672185 | 2026-01-14 00:24:28.672432 | TASK [bindep : Look for bindep fallback file] 2026-01-14 00:24:28.710963 | controller | skipping: Conditional result was False 2026-01-14 00:24:28.731333 | 2026-01-14 00:24:28.731610 | TASK [bindep : Define bindep_file fact] 2026-01-14 00:24:28.771922 | controller | skipping: Conditional result was False 2026-01-14 00:24:28.787474 | 2026-01-14 00:24:28.787631 | TASK [bindep : Include bindep tasks] 2026-01-14 00:24:28.825179 | controller | skipping: Conditional result was False 2026-01-14 00:24:28.839762 | 2026-01-14 00:24:28.840291 | TASK [bindep : Include install tasks] 2026-01-14 00:24:28.867041 | controller | skipping: Conditional result was False 2026-01-14 00:24:28.881809 | 2026-01-14 00:24:28.881967 | LOOP [bindep : Include package tasks] 2026-01-14 00:24:28.969538 | 2026-01-14 00:24:28.969876 | TASK [Run test-setup role] 2026-01-14 00:24:28.994870 | controller | ok 2026-01-14 00:24:29.024746 | 2026-01-14 00:24:29.024887 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-14 00:24:29.735556 | controller | ok 2026-01-14 00:24:29.749813 | 2026-01-14 00:24:29.749972 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-14 00:24:30.125236 | controller | skipping: Conditional result was False 2026-01-14 00:24:30.187367 | 2026-01-14 00:24:30.187497 | PLAY RECAP 2026-01-14 00:24:30.187570 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-14 00:24:30.187610 | 2026-01-14 00:24:30.308134 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-14 00:24:30.309850 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-14 00:24:30.924898 | 2026-01-14 00:24:30.925027 | PLAY [controller] 2026-01-14 00:24:30.946327 | 2026-01-14 00:24:30.946452 | TASK [Create the /root directory] 2026-01-14 00:24:32.055340 | controller | ok 2026-01-14 00:24:32.069308 | 2026-01-14 00:24:32.069517 | TASK [Install glibc-langpack-en] 2026-01-14 00:24:40.455298 | controller | ok: Nothing to do 2026-01-14 00:24:40.466552 | 2026-01-14 00:24:40.466659 | TASK [Ensure controller directory exists] 2026-01-14 00:24:41.277749 | controller | changed 2026-01-14 00:24:41.291908 | 2026-01-14 00:24:41.292060 | TASK [Install container runtime] 2026-01-14 00:24:41.352901 | controller | ok 2026-01-14 00:24:41.410598 | 2026-01-14 00:24:41.410760 | LOOP [ensure-podman : Find distribution installation] 2026-01-14 00:24:41.439092 | controller | ok: "/var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-14 00:24:41.454497 | controller | included: /var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-14 00:24:41.461188 | 2026-01-14 00:24:41.461259 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-14 00:26:54.842076 | controller | changed 2026-01-14 00:26:54.856943 | 2026-01-14 00:26:54.857082 | TASK [ensure-podman : Fetch podman version] 2026-01-14 00:26:56.029872 | controller | Client: Podman Engine 2026-01-14 00:26:56.070519 | controller | Version: 4.6.2 2026-01-14 00:26:56.070572 | controller | API Version: 4.6.2 2026-01-14 00:26:56.070581 | controller | Go Version: go1.19.12 2026-01-14 00:26:56.070600 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-14 00:26:56.070609 | controller | OS/Arch: linux/amd64 2026-01-14 00:26:56.237638 | controller | ok: Runtime: 0:00:00.264256 2026-01-14 00:26:56.247742 | 2026-01-14 00:26:56.247857 | TASK [ensure-podman : Print podman version installed] 2026-01-14 00:26:56.299957 | Podman version: Client: Podman Engine 2026-01-14 00:26:56.300278 | Version: 4.6.2 2026-01-14 00:26:56.300345 | API Version: 4.6.2 2026-01-14 00:26:56.300427 | Go Version: go1.19.12 2026-01-14 00:26:56.300473 | Built: Mon Aug 28 19:38:31 2023 2026-01-14 00:26:56.300525 | OS/Arch: linux/amd64 2026-01-14 00:26:56.314357 | 2026-01-14 00:26:56.314501 | TASK [ensure-podman : Validate podman engine] 2026-01-14 00:26:56.679884 | controller | skipping: Conditional result was False 2026-01-14 00:26:56.696876 | 2026-01-14 00:26:56.697148 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-14 00:26:56.725472 | controller | skipping: Conditional result was False 2026-01-14 00:26:56.752356 | 2026-01-14 00:26:56.752550 | TASK [Ensure python3.8 is present] 2026-01-14 00:26:56.779400 | controller | skipping: Conditional result was False 2026-01-14 00:26:56.789062 | 2026-01-14 00:26:56.789168 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-14 00:26:56.813789 | controller | ok 2026-01-14 00:26:56.842732 | 2026-01-14 00:26:56.842950 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-14 00:27:00.436832 | controller | ok: Nothing to do 2026-01-14 00:27:00.454273 | 2026-01-14 00:27:00.454525 | TASK [our-ensure-python : Also install python3-devel] 2026-01-14 00:27:16.838576 | controller | changed 2026-01-14 00:27:16.862360 | 2026-01-14 00:27:16.862514 | TASK [Run ensure-virtualenv role] 2026-01-14 00:27:16.902178 | controller | ok 2026-01-14 00:27:16.937853 | 2026-01-14 00:27:16.937960 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-14 00:27:17.722986 | controller | /usr/bin/virtualenv 2026-01-14 00:27:18.335111 | controller | ok: Runtime: 0:00:00.004421 2026-01-14 00:27:18.348370 | 2026-01-14 00:27:18.348526 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-14 00:27:18.386076 | controller | skipping: Conditional result was False 2026-01-14 00:27:18.386425 | controller | ok: All items complete 2026-01-14 00:27:18.386469 | 2026-01-14 00:27:18.435924 | 2026-01-14 00:27:18.436249 | TASK [Find the full path of the Python interpreter] 2026-01-14 00:27:19.277549 | controller | /usr/bin/python3 2026-01-14 00:27:19.813195 | controller | ok 2026-01-14 00:27:19.827132 | 2026-01-14 00:27:19.827674 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-14 00:27:21.721150 | controller | created virtual environment CPython3.11.0.final.0-64 in 884ms 2026-01-14 00:27:21.800779 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-14 00:27:21.800836 | 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:27:21.800852 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-14 00:27:21.800873 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-14 00:27:22.212145 | controller | changed 2026-01-14 00:27:22.218125 | 2026-01-14 00:27:22.218187 | TASK [Set selinux package] 2026-01-14 00:27:22.247651 | controller | ok 2026-01-14 00:27:22.252833 | 2026-01-14 00:27:22.252894 | TASK [Set selinux package (Fedora)] 2026-01-14 00:27:22.282659 | controller | ok 2026-01-14 00:27:22.287638 | 2026-01-14 00:27:22.287715 | TASK [Install selinux into virtualenv] 2026-01-14 00:27:25.168036 | controller | Collecting selinux-please-lie-to-me 2026-01-14 00:27:25.227581 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-14 00:27:25.719708 | controller | Collecting setuptools<50.0.0 2026-01-14 00:27:25.725740 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-14 00:27:25.781531 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.5 MB/s eta 0:00:00 2026-01-14 00:27:25.948856 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-14 00:27:25.949170 | controller | Attempting uninstall: setuptools 2026-01-14 00:27:25.952846 | controller | Found existing installation: setuptools 62.6.0 2026-01-14 00:27:26.050020 | controller | Uninstalling setuptools-62.6.0: 2026-01-14 00:27:26.061783 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-14 00:27:26.832027 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-14 00:27:27.060750 | controller | 2026-01-14 00:27:27.380137 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-14 00:27:27.380185 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-14 00:27:27.675071 | controller | ok: Runtime: 0:00:04.336062 2026-01-14 00:27:27.689291 | 2026-01-14 00:27:27.689482 | TASK [Install pytest-forked into virtualenv] 2026-01-14 00:27:29.201643 | controller | Collecting pytest-forked 2026-01-14 00:27:29.271850 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-14 00:27:29.338811 | controller | Collecting py 2026-01-14 00:27:29.343394 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-14 00:27:29.386155 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.3 MB/s eta 0:00:00 2026-01-14 00:27:29.569321 | controller | Collecting pytest>=3.10 2026-01-14 00:27:29.573820 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-14 00:27:29.599546 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 16.4 MB/s eta 0:00:00 2026-01-14 00:27:29.662727 | controller | Collecting iniconfig>=1.0.1 2026-01-14 00:27:29.669885 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-14 00:27:29.736291 | controller | Collecting packaging>=22 2026-01-14 00:27:29.742638 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-14 00:27:29.753434 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 7.3 MB/s eta 0:00:00 2026-01-14 00:27:29.797881 | controller | Collecting pluggy<2,>=1.5 2026-01-14 00:27:29.803980 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-14 00:27:29.883092 | controller | Collecting pygments>=2.7.2 2026-01-14 00:27:29.890541 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-14 00:27:29.928531 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 35.9 MB/s eta 0:00:00 2026-01-14 00:27:30.070333 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-14 00:27:32.480489 | 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:27:32.495975 | controller | 2026-01-14 00:27:32.748933 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-14 00:27:32.748988 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-14 00:27:33.093070 | controller | ok: Runtime: 0:00:04.268259 2026-01-14 00:27:33.102079 | 2026-01-14 00:27:33.102197 | TASK [Update pip] 2026-01-14 00:27:34.607056 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-14 00:27:34.968128 | controller | Collecting pip 2026-01-14 00:27:35.048168 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-14 00:27:35.132272 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 22.4 MB/s eta 0:00:00 2026-01-14 00:27:35.271370 | controller | Installing collected packages: pip 2026-01-14 00:27:35.271662 | controller | Attempting uninstall: pip 2026-01-14 00:27:35.275467 | controller | Found existing installation: pip 22.2.2 2026-01-14 00:27:35.503940 | controller | Uninstalling pip-22.2.2: 2026-01-14 00:27:35.529879 | controller | Successfully uninstalled pip-22.2.2 2026-01-14 00:27:37.277427 | controller | Successfully installed pip-25.3 2026-01-14 00:27:37.995408 | controller | ok: Runtime: 0:00:03.553930 2026-01-14 00:27:38.001451 | 2026-01-14 00:27:38.001543 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-14 00:27:38.884673 | controller | changed 2026-01-14 00:27:38.898593 | 2026-01-14 00:27:38.898735 | TASK [Install ansible into virtualenv] 2026-01-14 00:27:40.141713 | controller | Processing ./src/github.com/ansible/ansible 2026-01-14 00:27:40.146890 | controller | Installing build dependencies: started 2026-01-14 00:27:42.100785 | controller | Installing build dependencies: finished with status 'done' 2026-01-14 00:27:43.571402 | controller | Getting requirements to build wheel: started 2026-01-14 00:27:43.571511 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-14 00:27:43.572754 | controller | Preparing metadata (pyproject.toml): started 2026-01-14 00:27:44.399837 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-14 00:27:44.400668 | 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:27:44.405097 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-14 00:27:44.823562 | controller | ERROR 2026-01-14 00:27:44.823828 | controller | { 2026-01-14 00:27:44.823900 | controller | "delta": "0:00:04.987607", 2026-01-14 00:27:44.823944 | controller | "end": "2026-01-14 00:27:44.565809", 2026-01-14 00:27:44.823981 | controller | "msg": "non-zero return code", 2026-01-14 00:27:44.824035 | controller | "rc": 1, 2026-01-14 00:27:44.824073 | controller | "start": "2026-01-14 00:27:39.578202" 2026-01-14 00:27:44.824109 | controller | } failure 2026-01-14 00:27:44.826416 | 2026-01-14 00:27:44.826525 | PLAY RECAP 2026-01-14 00:27:44.826617 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-14 00:27:44.826673 | 2026-01-14 00:27:44.950076 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-14 00:27:44.951940 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-14 00:27:45.565237 | 2026-01-14 00:27:45.565366 | PLAY [all] 2026-01-14 00:27:45.589054 | 2026-01-14 00:27:45.589190 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-14 00:27:47.412936 | controller | changed: non-zero return code 2026-01-14 00:27:47.427835 | 2026-01-14 00:27:47.428051 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-14 00:27:47.456130 | controller | skipping: Conditional result was False 2026-01-14 00:27:47.470194 | 2026-01-14 00:27:47.470485 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-14 00:27:47.514965 | 2026-01-14 00:27:47.515247 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-14 00:27:47.558798 | 2026-01-14 00:27:47.559229 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-14 00:27:47.586722 | controller | skipping: Conditional result was False 2026-01-14 00:27:47.602433 | 2026-01-14 00:27:47.602846 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-14 00:27:47.646075 | 2026-01-14 00:27:47.646371 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-14 00:27:47.674526 | controller | skipping: Conditional result was False 2026-01-14 00:27:47.691079 | 2026-01-14 00:27:47.691245 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-14 00:27:47.719050 | controller | skipping: Conditional result was False 2026-01-14 00:27:47.737288 | 2026-01-14 00:27:47.737491 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-14 00:27:47.765169 | controller | skipping: Conditional result was False 2026-01-14 00:27:47.814375 | 2026-01-14 00:27:47.814496 | PLAY RECAP 2026-01-14 00:27:47.814567 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-14 00:27:47.814604 | 2026-01-14 00:27:47.915583 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-14 00:27:47.917577 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-14 00:27:48.523509 | 2026-01-14 00:27:48.523632 | PLAY [all:!appliance*] 2026-01-14 00:27:48.545394 | 2026-01-14 00:27:48.545503 | TASK [unregister the node] 2026-01-14 00:27:48.900218 | controller | skipping: Conditional result was False 2026-01-14 00:27:48.909106 | 2026-01-14 00:27:48.909279 | TASK [include_role : fetch-output] 2026-01-14 00:27:48.962413 | controller | ok 2026-01-14 00:27:48.990097 | 2026-01-14 00:27:48.990223 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-14 00:27:49.066327 | controller | skipping: Conditional result was False 2026-01-14 00:27:49.075291 | 2026-01-14 00:27:49.075424 | TASK [fetch-output : Set log path for single node] 2026-01-14 00:27:49.120123 | controller | ok 2026-01-14 00:27:49.128115 | 2026-01-14 00:27:49.128218 | LOOP [fetch-output : Ensure local output dirs] 2026-01-14 00:27:49.575810 | controller -> localhost | ok: "/var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/logs" 2026-01-14 00:27:49.865833 | controller -> localhost | changed: "/var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/artifacts" 2026-01-14 00:27:50.151367 | controller -> localhost | changed: "/var/lib/zuul/builds/4c63f1aa88c2408eabbd7ad793769cde/work/docs" 2026-01-14 00:27:50.182660 | 2026-01-14 00:27:50.182954 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-14 00:27:52.439652 | controller | changed: 2026-01-14 00:27:52.440042 | controller | .d..t...... ./ 2026-01-14 00:27:52.440112 | controller | cd+++++++++ controller/ 2026-01-14 00:27:52.440207 | controller | changed: All items complete 2026-01-14 00:27:52.440260 | 2026-01-14 00:27:54.458306 | controller | changed: .d..t...... ./ 2026-01-14 00:27:56.467128 | controller | changed: .d..t...... ./ 2026-01-14 00:27:56.491347 | 2026-01-14 00:27:56.491519 | TASK [include_role : fetch-output-openshift] 2026-01-14 00:27:56.507001 | controller | skipping: Conditional result was False 2026-01-14 00:27:56.513995 | 2026-01-14 00:27:56.514074 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-14 00:27:56.539409 | controller | skipping: Conditional result was False 2026-01-14 00:27:56.547276 | controller | skipping: Conditional result was False 2026-01-14 00:27:56.575781 | 2026-01-14 00:27:56.575916 | PLAY [localhost] 2026-01-14 00:27:56.588695 | 2026-01-14 00:27:56.588767 | TASK [Run Zuul manifest role] 2026-01-14 00:27:56.607035 | localhost | ok 2026-01-14 00:27:56.620360 | 2026-01-14 00:27:56.620450 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-14 00:27:57.015595 | localhost | changed 2026-01-14 00:27:57.020222 | 2026-01-14 00:27:57.020301 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-14 00:27:57.049422 | localhost | ok 2026-01-14 00:27:57.057813 | 2026-01-14 00:27:57.057875 | TASK [Set zuul-log-path fact] 2026-01-14 00:27:57.076754 | localhost | ok 2026-01-14 00:27:57.120315 | 2026-01-14 00:27:57.120442 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-14 00:27:57.149397 | localhost | ok 2026-01-14 00:27:57.157139 | 2026-01-14 00:27:57.157205 | LOOP [Run upload-logs-swift role] 2026-01-14 00:27:57.192125 | localhost | Output suppressed because no_log was given 2026-01-14 00:27:57.229326 | 2026-01-14 00:27:57.229488 | TASK [Set zuul-log-path fact] 2026-01-14 00:27:57.254471 | localhost | skipping: Conditional result was False 2026-01-14 00:27:57.261108 | 2026-01-14 00:27:57.261207 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-14 00:27:57.641259 | localhost -> localhost | ok: Runtime: 0:00:00.005389 2026-01-14 00:27:57.646822 | 2026-01-14 00:27:57.646887 | TASK [upload-logs-swift : Upload logs to swift]