2026-01-08 00:07:08.977483 | Job console starting... 2026-01-08 00:07:08.988709 | Updating repositories 2026-01-08 00:07:09.192669 | Preparing job workspace 2026-01-08 00:07:25.147864 | Running Ansible setup... 2026-01-08 00:07:33.172072 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-08 00:07:33.862605 | 2026-01-08 00:07:33.862766 | PLAY [localhost] 2026-01-08 00:07:33.872628 | 2026-01-08 00:07:33.872790 | TASK [Gathering Facts] 2026-01-08 00:07:34.947695 | localhost | ok 2026-01-08 00:07:34.966884 | 2026-01-08 00:07:34.967070 | TASK [Setup log path fact] 2026-01-08 00:07:34.988305 | localhost | ok 2026-01-08 00:07:35.008276 | 2026-01-08 00:07:35.008448 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-08 00:07:35.039130 | localhost | ok 2026-01-08 00:07:35.051542 | 2026-01-08 00:07:35.051685 | TASK [emit-job-header : Print job information] 2026-01-08 00:07:35.094092 | # Job Information 2026-01-08 00:07:35.094287 | Ansible Version: 2.15.12 2026-01-08 00:07:35.094334 | Job: ansible-test-sanity-docker-devel 2026-01-08 00:07:35.094367 | Pipeline: periodic 2026-01-08 00:07:35.094397 | Executor: ze03.softwarefactory-project.io 2026-01-08 00:07:35.094426 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-08 00:07:35.094460 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/71e/ansible/71e60d410f534d13a17c0484a2b918b3/ 2026-01-08 00:07:35.094493 | Event ID: d4752e8c0ffe4b90a8171373176f7c90 2026-01-08 00:07:35.099819 | 2026-01-08 00:07:35.099914 | LOOP [emit-job-header : Print node information] 2026-01-08 00:07:35.222698 | localhost | ok: 2026-01-08 00:07:35.223095 | localhost | # Node Information 2026-01-08 00:07:35.223156 | localhost | Inventory Hostname: controller 2026-01-08 00:07:35.223199 | localhost | Hostname: np0005577438 2026-01-08 00:07:35.223241 | localhost | Username: zuul 2026-01-08 00:07:35.223285 | localhost | Distro: Fedora 37 2026-01-08 00:07:35.223326 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-08 00:07:35.223365 | localhost | Region: ca-ymq-1 2026-01-08 00:07:35.223444 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-08 00:07:35.223481 | localhost | Product Name: OpenStack Nova 2026-01-08 00:07:35.223519 | localhost | Interface IP: 162.253.55.49 2026-01-08 00:07:35.238760 | 2026-01-08 00:07:35.238913 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-08 00:07:35.673149 | localhost -> localhost | changed 2026-01-08 00:07:35.680663 | 2026-01-08 00:07:35.680876 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-08 00:07:36.861907 | localhost -> localhost | changed 2026-01-08 00:07:36.911058 | 2026-01-08 00:07:36.911141 | PLAY [all:!appliance*] 2026-01-08 00:07:36.929458 | 2026-01-08 00:07:36.929601 | TASK [include_role : start-zuul-console] 2026-01-08 00:07:36.950465 | controller | ok 2026-01-08 00:07:36.964901 | 2026-01-08 00:07:36.965020 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-08 00:07:37.395092 | controller | ok 2026-01-08 00:07:37.412428 | 2026-01-08 00:07:37.412563 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-08 00:07:39.328706 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-08 00:07:39.338572 | 2026-01-08 00:07:39.338712 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-08 00:07:39.885384 | controller | skipping: Conditional result was False 2026-01-08 00:07:39.902022 | 2026-01-08 00:07:39.902207 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-08 00:07:39.931419 | controller | skipping: Conditional result was False 2026-01-08 00:07:39.945885 | 2026-01-08 00:07:39.946248 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-08 00:07:39.973848 | controller | skipping: Conditional result was False 2026-01-08 00:07:39.988991 | 2026-01-08 00:07:39.989148 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-08 00:07:40.014777 | controller | skipping: Conditional result was False 2026-01-08 00:07:40.025266 | 2026-01-08 00:07:40.025411 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-08 00:07:40.050844 | controller | skipping: Conditional result was False 2026-01-08 00:07:40.060261 | 2026-01-08 00:07:40.060401 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-08 00:07:40.085843 | controller | skipping: Conditional result was False 2026-01-08 00:07:40.102770 | 2026-01-08 00:07:40.102907 | TASK [Disable Fedora Modular] 2026-01-08 00:07:40.344541 | controller | changed 2026-01-08 00:07:40.355400 | 2026-01-08 00:07:40.355614 | TASK [Enable EPEL] 2026-01-08 00:07:40.396000 | controller | skipping: Conditional result was False 2026-01-08 00:07:40.406914 | 2026-01-08 00:07:40.407092 | TASK [Register the RHEL node] 2026-01-08 00:07:40.954958 | 2026-01-08 00:07:40.955617 | TASK [Show the subscription-manager status] 2026-01-08 00:07:41.539861 | controller | skipping: Conditional result was False 2026-01-08 00:07:41.553883 | 2026-01-08 00:07:41.554030 | TASK [Enable EPEL on RHEL] 2026-01-08 00:07:42.104370 | controller | skipping: Conditional result was False 2026-01-08 00:07:42.120334 | 2026-01-08 00:07:42.120516 | TASK [Install git and tox] 2026-01-08 00:09:50.310411 | controller | changed 2026-01-08 00:09:50.317426 | 2026-01-08 00:09:50.317520 | TASK [include_role : prepare-workspace] 2026-01-08 00:09:50.350105 | controller | ok 2026-01-08 00:09:50.383502 | 2026-01-08 00:09:50.383654 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-08 00:09:50.609131 | controller | ok 2026-01-08 00:09:50.618025 | 2026-01-08 00:09:50.618110 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-08 00:10:03.159485 | controller | Output suppressed because no_log was given 2026-01-08 00:10:03.204259 | 2026-01-08 00:10:03.204375 | TASK [include_role : prepare-workspace-openshift] 2026-01-08 00:10:03.228191 | controller | skipping: Conditional result was False 2026-01-08 00:10:03.253948 | 2026-01-08 00:10:03.254060 | PLAY [all:!appliance] 2026-01-08 00:10:03.274172 | 2026-01-08 00:10:03.274299 | TASK [Run add-build-sshkey role (RSA)] 2026-01-08 00:10:03.305010 | controller | ok 2026-01-08 00:10:03.324221 | 2026-01-08 00:10:03.324373 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-08 00:10:03.584452 | controller -> localhost | ok 2026-01-08 00:10:03.593135 | 2026-01-08 00:10:03.593251 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-08 00:10:03.633005 | controller | ok 2026-01-08 00:10:03.670847 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-08 00:10:03.684066 | 2026-01-08 00:10:03.684205 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-08 00:10:04.239765 | controller -> localhost | Generating public/private rsa key pair. 2026-01-08 00:10:04.240210 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_rsa. 2026-01-08 00:10:04.240275 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_rsa.pub. 2026-01-08 00:10:04.240323 | controller -> localhost | The key fingerprint is: 2026-01-08 00:10:04.240367 | controller -> localhost | SHA256:vo0wU6e2h47OdThgSV0D504lNUNCvBaFyoNbg3LpeOM zuul-build-sshkey 2026-01-08 00:10:04.240409 | controller -> localhost | The key's randomart image is: 2026-01-08 00:10:04.240450 | controller -> localhost | +---[RSA 2048]----+ 2026-01-08 00:10:04.240494 | controller -> localhost | | .+B=B | 2026-01-08 00:10:04.240538 | controller -> localhost | | . ++= o | 2026-01-08 00:10:04.240580 | controller -> localhost | | .=..oo | 2026-01-08 00:10:04.240622 | controller -> localhost | | ..=.*oo | 2026-01-08 00:10:04.240663 | controller -> localhost | | =+oS+o | 2026-01-08 00:10:04.240809 | controller -> localhost | | ..=+ + | 2026-01-08 00:10:04.240873 | controller -> localhost | | o+.B.. | 2026-01-08 00:10:04.240920 | controller -> localhost | | .EB.B. | 2026-01-08 00:10:04.240963 | controller -> localhost | | .+.=.. | 2026-01-08 00:10:04.241009 | controller -> localhost | +----[SHA256]-----+ 2026-01-08 00:10:04.241100 | controller -> localhost | ok: Runtime: 0:00:00.114589 2026-01-08 00:10:04.258037 | 2026-01-08 00:10:04.258209 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-08 00:10:04.292159 | controller | ok 2026-01-08 00:10:04.307469 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-08 00:10:04.321674 | 2026-01-08 00:10:04.321811 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-08 00:10:04.347212 | controller | skipping: Conditional result was False 2026-01-08 00:10:04.357053 | 2026-01-08 00:10:04.357164 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-08 00:10:04.826336 | controller | changed 2026-01-08 00:10:04.835500 | 2026-01-08 00:10:04.835619 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-08 00:10:05.065472 | controller | ok 2026-01-08 00:10:05.073476 | 2026-01-08 00:10:05.073568 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-08 00:10:05.748990 | controller | changed 2026-01-08 00:10:05.756040 | 2026-01-08 00:10:05.756140 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-08 00:10:06.431408 | controller | changed 2026-01-08 00:10:06.439693 | 2026-01-08 00:10:06.439809 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-08 00:10:06.466100 | controller | skipping: Conditional result was False 2026-01-08 00:10:06.475388 | 2026-01-08 00:10:06.475522 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-08 00:10:06.928404 | controller -> localhost | changed 2026-01-08 00:10:06.946187 | 2026-01-08 00:10:06.946330 | TASK [add-build-sshkey : Add back temp key] 2026-01-08 00:10:07.287703 | controller -> localhost | Identity added: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_rsa (zuul-build-sshkey) 2026-01-08 00:10:07.288175 | controller -> localhost | ok: Runtime: 0:00:00.013692 2026-01-08 00:10:07.298787 | 2026-01-08 00:10:07.299021 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-08 00:10:07.640754 | controller | ok 2026-01-08 00:10:07.647016 | 2026-01-08 00:10:07.647109 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-08 00:10:07.671321 | controller | skipping: Conditional result was False 2026-01-08 00:10:07.684064 | 2026-01-08 00:10:07.684194 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-08 00:10:07.709282 | controller | ok 2026-01-08 00:10:07.733713 | 2026-01-08 00:10:07.733889 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-08 00:10:07.962705 | controller -> localhost | ok 2026-01-08 00:10:07.969435 | 2026-01-08 00:10:07.969522 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-08 00:10:07.991516 | controller | ok 2026-01-08 00:10:08.002671 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-08 00:10:08.009071 | 2026-01-08 00:10:08.009158 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-08 00:10:08.278082 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-08 00:10:08.278288 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_ecdsa. 2026-01-08 00:10:08.278334 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_ecdsa.pub. 2026-01-08 00:10:08.278380 | controller -> localhost | The key fingerprint is: 2026-01-08 00:10:08.278415 | controller -> localhost | SHA256:fn005b564Slqez45BU58Pc9GNronqdFZzvEPlV0JT4s zuul-build-sshkey 2026-01-08 00:10:08.278446 | controller -> localhost | The key's randomart image is: 2026-01-08 00:10:08.278476 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-08 00:10:08.278505 | controller -> localhost | | . . | 2026-01-08 00:10:08.278534 | controller -> localhost | | = o| 2026-01-08 00:10:08.278564 | controller -> localhost | | .E ++| 2026-01-08 00:10:08.278593 | controller -> localhost | | + *B| 2026-01-08 00:10:08.278623 | controller -> localhost | | S o *BB| 2026-01-08 00:10:08.278650 | controller -> localhost | | . ..+=**| 2026-01-08 00:10:08.278674 | controller -> localhost | | . ...oO+=| 2026-01-08 00:10:08.278702 | controller -> localhost | | . ..@ *o| 2026-01-08 00:10:08.278745 | controller -> localhost | | .+*oO..| 2026-01-08 00:10:08.278778 | controller -> localhost | +----[SHA256]-----+ 2026-01-08 00:10:08.278833 | controller -> localhost | ok: Runtime: 0:00:00.008340 2026-01-08 00:10:08.286448 | 2026-01-08 00:10:08.286537 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-08 00:10:08.307618 | controller | ok 2026-01-08 00:10:08.317429 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-08 00:10:08.330120 | 2026-01-08 00:10:08.330262 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-08 00:10:08.354829 | controller | skipping: Conditional result was False 2026-01-08 00:10:08.363675 | 2026-01-08 00:10:08.363853 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-08 00:10:08.632595 | controller | changed 2026-01-08 00:10:08.639815 | 2026-01-08 00:10:08.639919 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-08 00:10:08.846135 | controller | ok 2026-01-08 00:10:08.853680 | 2026-01-08 00:10:08.853817 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-08 00:10:09.469338 | controller | changed 2026-01-08 00:10:09.477269 | 2026-01-08 00:10:09.477400 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-08 00:10:10.099432 | controller | changed 2026-01-08 00:10:10.116094 | 2026-01-08 00:10:10.116284 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-08 00:10:10.143515 | controller | skipping: Conditional result was False 2026-01-08 00:10:10.200071 | 2026-01-08 00:10:10.200213 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-08 00:10:10.449875 | controller -> localhost | changed 2026-01-08 00:10:10.480372 | 2026-01-08 00:10:10.480566 | TASK [add-build-sshkey : Add back temp key] 2026-01-08 00:10:10.822907 | controller -> localhost | Identity added: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/71e60d410f534d13a17c0484a2b918b3_id_ecdsa (zuul-build-sshkey) 2026-01-08 00:10:10.823186 | controller -> localhost | ok: Runtime: 0:00:00.013476 2026-01-08 00:10:10.832682 | 2026-01-08 00:10:10.832819 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-08 00:10:11.049389 | controller | ok 2026-01-08 00:10:11.056259 | 2026-01-08 00:10:11.056386 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-08 00:10:11.080654 | controller | skipping: Conditional result was False 2026-01-08 00:10:11.091791 | 2026-01-08 00:10:11.091890 | TASK [include_role : remove-zuul-sshkey] 2026-01-08 00:10:11.105528 | controller | skipping: Conditional result was False 2026-01-08 00:10:11.112283 | 2026-01-08 00:10:11.112401 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-08 00:10:11.339136 | controller | ok: "logs" 2026-01-08 00:10:11.339594 | controller | ok: All items complete 2026-01-08 00:10:11.339642 | 2026-01-08 00:10:11.541203 | controller | ok: "artifacts" 2026-01-08 00:10:11.728918 | controller | ok: "docs" 2026-01-08 00:10:11.748213 | 2026-01-08 00:10:11.748414 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-08 00:10:11.999379 | controller | changed: "logs" 2026-01-08 00:10:12.195698 | controller | changed: "artifacts" 2026-01-08 00:10:12.392908 | controller | changed: "docs" 2026-01-08 00:10:12.459028 | 2026-01-08 00:10:12.459213 | PLAY RECAP 2026-01-08 00:10:12.459298 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-08 00:10:12.459344 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-08 00:10:12.459371 | 2026-01-08 00:10:12.593050 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-08 00:10:12.594343 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-08 00:10:13.195421 | 2026-01-08 00:10:13.195571 | PLAY [all] 2026-01-08 00:10:13.218714 | 2026-01-08 00:10:13.218848 | TASK [Install binary dependencies] 2026-01-08 00:10:13.269057 | controller | ok 2026-01-08 00:10:13.291014 | 2026-01-08 00:10:13.291125 | TASK [bindep : Include find tasks] 2026-01-08 00:10:13.320761 | controller | ok 2026-01-08 00:10:13.330952 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-08 00:10:13.337393 | 2026-01-08 00:10:13.337469 | TASK [bindep : Look for bindep.txt] 2026-01-08 00:10:13.691409 | controller | ok 2026-01-08 00:10:13.700690 | 2026-01-08 00:10:13.700863 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:10:13.726432 | controller | skipping: Conditional result was False 2026-01-08 00:10:13.736064 | 2026-01-08 00:10:13.736246 | TASK [bindep : Look for other-requirements.txt] 2026-01-08 00:10:13.965373 | controller | ok 2026-01-08 00:10:13.973441 | 2026-01-08 00:10:13.973549 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:10:13.999586 | controller | skipping: Conditional result was False 2026-01-08 00:10:14.008195 | 2026-01-08 00:10:14.008337 | TASK [bindep : Look for bindep fallback file] 2026-01-08 00:10:14.044933 | controller | skipping: Conditional result was False 2026-01-08 00:10:14.054860 | 2026-01-08 00:10:14.055012 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:10:14.080801 | controller | skipping: Conditional result was False 2026-01-08 00:10:14.090041 | 2026-01-08 00:10:14.090173 | TASK [bindep : Include bindep tasks] 2026-01-08 00:10:14.116655 | controller | skipping: Conditional result was False 2026-01-08 00:10:14.126282 | 2026-01-08 00:10:14.126393 | TASK [bindep : Include install tasks] 2026-01-08 00:10:14.152387 | controller | skipping: Conditional result was False 2026-01-08 00:10:14.162236 | 2026-01-08 00:10:14.162348 | LOOP [bindep : Include package tasks] 2026-01-08 00:10:14.244398 | 2026-01-08 00:10:14.244684 | TASK [Run test-setup role] 2026-01-08 00:10:14.276720 | controller | ok 2026-01-08 00:10:14.311762 | 2026-01-08 00:10:14.311879 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-08 00:10:14.573791 | controller | ok 2026-01-08 00:10:14.588255 | 2026-01-08 00:10:14.588393 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-08 00:10:15.141564 | controller | skipping: Conditional result was False 2026-01-08 00:10:15.171892 | 2026-01-08 00:10:15.172064 | PLAY RECAP 2026-01-08 00:10:15.172134 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-08 00:10:15.172163 | 2026-01-08 00:10:15.290551 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-08 00:10:15.292268 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-08 00:10:15.941591 | 2026-01-08 00:10:15.941804 | PLAY [controller] 2026-01-08 00:10:15.962417 | 2026-01-08 00:10:15.962521 | TASK [Create the /root directory] 2026-01-08 00:10:16.372872 | controller | ok 2026-01-08 00:10:16.379520 | 2026-01-08 00:10:16.385799 | TASK [Install glibc-langpack-en] 2026-01-08 00:10:20.293889 | controller | ok: Nothing to do 2026-01-08 00:10:20.306293 | 2026-01-08 00:10:20.306423 | TASK [Ensure controller directory exists] 2026-01-08 00:10:20.529414 | controller | changed 2026-01-08 00:10:20.539752 | 2026-01-08 00:10:20.539817 | TASK [Install container runtime] 2026-01-08 00:10:20.596242 | controller | ok 2026-01-08 00:10:20.655490 | 2026-01-08 00:10:20.655649 | LOOP [ensure-podman : Find distribution installation] 2026-01-08 00:10:20.691853 | controller | ok: "/var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-08 00:10:20.702055 | controller | included: /var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-08 00:10:20.711140 | 2026-01-08 00:10:20.711324 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-08 00:11:25.670139 | controller | changed 2026-01-08 00:11:25.680531 | 2026-01-08 00:11:25.680686 | TASK [ensure-podman : Fetch podman version] 2026-01-08 00:11:26.212383 | controller | Client: Podman Engine 2026-01-08 00:11:26.212519 | controller | Version: 4.6.2 2026-01-08 00:11:26.212594 | controller | API Version: 4.6.2 2026-01-08 00:11:26.212665 | controller | Go Version: go1.19.12 2026-01-08 00:11:26.212783 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-08 00:11:26.212857 | controller | OS/Arch: linux/amd64 2026-01-08 00:11:26.723671 | controller | ok: Runtime: 0:00:00.185842 2026-01-08 00:11:26.745871 | 2026-01-08 00:11:26.746110 | TASK [ensure-podman : Print podman version installed] 2026-01-08 00:11:26.806997 | Podman version: Client: Podman Engine 2026-01-08 00:11:26.807263 | Version: 4.6.2 2026-01-08 00:11:26.807322 | API Version: 4.6.2 2026-01-08 00:11:26.807370 | Go Version: go1.19.12 2026-01-08 00:11:26.807426 | Built: Mon Aug 28 19:38:31 2023 2026-01-08 00:11:26.807483 | OS/Arch: linux/amd64 2026-01-08 00:11:26.819108 | 2026-01-08 00:11:26.819223 | TASK [ensure-podman : Validate podman engine] 2026-01-08 00:11:27.361417 | controller | skipping: Conditional result was False 2026-01-08 00:11:27.376702 | 2026-01-08 00:11:27.376910 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-08 00:11:27.403812 | controller | skipping: Conditional result was False 2026-01-08 00:11:27.429755 | 2026-01-08 00:11:27.429927 | TASK [Ensure python3.8 is present] 2026-01-08 00:11:27.457661 | controller | skipping: Conditional result was False 2026-01-08 00:11:27.470690 | 2026-01-08 00:11:27.470919 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-08 00:11:27.505090 | controller | ok 2026-01-08 00:11:27.537900 | 2026-01-08 00:11:27.538029 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-08 00:11:28.976755 | controller | ok: Nothing to do 2026-01-08 00:11:28.988234 | 2026-01-08 00:11:28.988361 | TASK [our-ensure-python : Also install python3-devel] 2026-01-08 00:11:37.423047 | controller | changed 2026-01-08 00:11:37.443148 | 2026-01-08 00:11:37.443309 | TASK [Run ensure-virtualenv role] 2026-01-08 00:11:37.469542 | controller | ok 2026-01-08 00:11:37.509866 | 2026-01-08 00:11:37.510006 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-08 00:11:37.728399 | controller | /usr/bin/virtualenv 2026-01-08 00:11:38.055153 | controller | ok: Runtime: 0:00:00.004753 2026-01-08 00:11:38.069362 | 2026-01-08 00:11:38.069542 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-08 00:11:38.093202 | controller | skipping: Conditional result was False 2026-01-08 00:11:38.093475 | controller | ok: All items complete 2026-01-08 00:11:38.093506 | 2026-01-08 00:11:38.125539 | 2026-01-08 00:11:38.125833 | TASK [Find the full path of the Python interpreter] 2026-01-08 00:11:38.379989 | controller | /usr/bin/python3 2026-01-08 00:11:38.700668 | controller | ok 2026-01-08 00:11:38.713636 | 2026-01-08 00:11:38.713832 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-08 00:11:39.498265 | controller | created virtual environment CPython3.11.0.final.0-64 in 431ms 2026-01-08 00:11:39.519520 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-08 00:11:39.519974 | 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-08 00:11:39.520233 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-08 00:11:39.520563 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-08 00:11:39.768190 | controller | changed 2026-01-08 00:11:39.775823 | 2026-01-08 00:11:39.775933 | TASK [Set selinux package] 2026-01-08 00:11:39.814100 | controller | ok 2026-01-08 00:11:39.820855 | 2026-01-08 00:11:39.820938 | TASK [Set selinux package (Fedora)] 2026-01-08 00:11:39.854295 | controller | ok 2026-01-08 00:11:39.863117 | 2026-01-08 00:11:39.863259 | TASK [Install selinux into virtualenv] 2026-01-08 00:11:53.377253 | controller | Collecting selinux-please-lie-to-me 2026-01-08 00:12:05.634584 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-08 00:12:05.942655 | controller | Collecting setuptools<50.0.0 2026-01-08 00:12:05.949432 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-08 00:12:05.985321 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.6 MB/s eta 0:00:00 2026-01-08 00:12:06.066474 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-08 00:12:06.066624 | controller | Attempting uninstall: setuptools 2026-01-08 00:12:06.069243 | controller | Found existing installation: setuptools 62.6.0 2026-01-08 00:12:06.128773 | controller | Uninstalling setuptools-62.6.0: 2026-01-08 00:12:06.136539 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-08 00:12:06.526502 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-08 00:12:18.005345 | controller | 2026-01-08 00:12:18.086593 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-08 00:12:18.086634 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-08 00:12:18.445429 | controller | ok: Runtime: 0:00:38.002547 2026-01-08 00:12:18.458906 | 2026-01-08 00:12:18.459072 | TASK [Install pytest-forked into virtualenv] 2026-01-08 00:12:30.253620 | controller | Collecting pytest-forked 2026-01-08 00:12:40.446679 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-08 00:12:40.489894 | controller | Collecting py 2026-01-08 00:12:40.493525 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-08 00:12:40.512871 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.5 MB/s eta 0:00:00 2026-01-08 00:12:40.627030 | controller | Collecting pytest>=3.10 2026-01-08 00:12:40.630616 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-08 00:12:40.647467 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.4 MB/s eta 0:00:00 2026-01-08 00:12:40.684898 | controller | Collecting iniconfig>=1.0.1 2026-01-08 00:12:40.688193 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-08 00:12:40.735266 | controller | Collecting packaging>=22 2026-01-08 00:12:40.738343 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-08 00:12:40.745207 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 12.2 MB/s eta 0:00:00 2026-01-08 00:12:40.785848 | controller | Collecting pluggy<2,>=1.5 2026-01-08 00:12:40.790001 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-08 00:12:40.848235 | controller | Collecting pygments>=2.7.2 2026-01-08 00:12:40.852289 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-08 00:12:40.872446 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 71.5 MB/s eta 0:00:00 2026-01-08 00:12:40.942838 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-08 00:12:42.001228 | 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-08 00:12:42.010026 | controller | 2026-01-08 00:12:42.085417 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-08 00:12:42.085466 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-08 00:12:42.520023 | controller | ok: Runtime: 0:00:23.415861 2026-01-08 00:12:42.531669 | 2026-01-08 00:12:42.531945 | TASK [Update pip] 2026-01-08 00:12:43.041564 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-08 00:12:52.828045 | controller | Collecting pip 2026-01-08 00:13:05.030320 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-08 00:13:05.085349 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 36.5 MB/s eta 0:00:00 2026-01-08 00:13:05.147542 | controller | Installing collected packages: pip 2026-01-08 00:13:05.147772 | controller | Attempting uninstall: pip 2026-01-08 00:13:05.149910 | controller | Found existing installation: pip 22.2.2 2026-01-08 00:13:05.284184 | controller | Uninstalling pip-22.2.2: 2026-01-08 00:13:05.299312 | controller | Successfully uninstalled pip-22.2.2 2026-01-08 00:13:06.058919 | controller | Successfully installed pip-25.3 2026-01-08 00:13:06.580359 | controller | ok: Runtime: 0:00:23.392679 2026-01-08 00:13:06.587271 | 2026-01-08 00:13:06.587390 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-08 00:13:06.801817 | controller | changed 2026-01-08 00:13:06.807853 | 2026-01-08 00:13:06.807945 | TASK [Install ansible into virtualenv] 2026-01-08 00:13:07.329900 | controller | Processing ./src/github.com/ansible/ansible 2026-01-08 00:13:07.333197 | controller | Installing build dependencies: started 2026-01-08 00:13:29.917039 | controller | Installing build dependencies: finished with status 'done' 2026-01-08 00:13:29.918187 | controller | Getting requirements to build wheel: started 2026-01-08 00:13:30.643438 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-08 00:13:30.644803 | controller | Preparing metadata (pyproject.toml): started 2026-01-08 00:13:31.110605 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-08 00:13:31.115897 | 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-08 00:13:31.120448 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-08 00:13:31.356238 | controller | ERROR 2026-01-08 00:13:31.356553 | controller | { 2026-01-08 00:13:31.356612 | controller | "delta": "0:00:24.143440", 2026-01-08 00:13:31.356656 | controller | "end": "2026-01-08 00:13:31.182545", 2026-01-08 00:13:31.356693 | controller | "msg": "non-zero return code", 2026-01-08 00:13:31.356803 | controller | "rc": 1, 2026-01-08 00:13:31.356850 | controller | "start": "2026-01-08 00:13:07.039105" 2026-01-08 00:13:31.356885 | controller | } failure 2026-01-08 00:13:31.359718 | 2026-01-08 00:13:31.359856 | PLAY RECAP 2026-01-08 00:13:31.359950 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-08 00:13:31.360002 | 2026-01-08 00:13:31.512224 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-08 00:13:31.513464 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-08 00:13:32.296536 | 2026-01-08 00:13:32.296689 | PLAY [all] 2026-01-08 00:13:32.323094 | 2026-01-08 00:13:32.323259 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-08 00:13:32.568658 | controller | changed: non-zero return code 2026-01-08 00:13:32.574814 | 2026-01-08 00:13:32.574949 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-08 00:13:32.599102 | controller | skipping: Conditional result was False 2026-01-08 00:13:32.605088 | 2026-01-08 00:13:32.605179 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-08 00:13:32.635989 | 2026-01-08 00:13:32.636123 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-08 00:13:32.676108 | 2026-01-08 00:13:32.676260 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-08 00:13:32.700097 | controller | skipping: Conditional result was False 2026-01-08 00:13:32.707465 | 2026-01-08 00:13:32.707549 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-08 00:13:32.727044 | 2026-01-08 00:13:32.727194 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-08 00:13:32.740749 | controller | skipping: Conditional result was False 2026-01-08 00:13:32.746825 | 2026-01-08 00:13:32.746923 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-08 00:13:32.760705 | controller | skipping: Conditional result was False 2026-01-08 00:13:32.766546 | 2026-01-08 00:13:32.766621 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-08 00:13:32.779979 | controller | skipping: Conditional result was False 2026-01-08 00:13:32.808256 | 2026-01-08 00:13:32.808366 | PLAY RECAP 2026-01-08 00:13:32.808410 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-08 00:13:32.808432 | 2026-01-08 00:13:32.908100 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-08 00:13:32.910028 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-08 00:13:33.614427 | 2026-01-08 00:13:33.614582 | PLAY [all:!appliance*] 2026-01-08 00:13:33.648497 | 2026-01-08 00:13:33.648654 | TASK [unregister the node] 2026-01-08 00:13:34.183020 | controller | skipping: Conditional result was False 2026-01-08 00:13:34.197797 | 2026-01-08 00:13:34.198010 | TASK [include_role : fetch-output] 2026-01-08 00:13:34.254114 | controller | ok 2026-01-08 00:13:34.311843 | 2026-01-08 00:13:34.312345 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-08 00:13:34.393688 | controller | skipping: Conditional result was False 2026-01-08 00:13:34.413135 | 2026-01-08 00:13:34.413419 | TASK [fetch-output : Set log path for single node] 2026-01-08 00:13:34.467555 | controller | ok 2026-01-08 00:13:34.473385 | 2026-01-08 00:13:34.473476 | LOOP [fetch-output : Ensure local output dirs] 2026-01-08 00:13:34.935651 | controller -> localhost | ok: "/var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/logs" 2026-01-08 00:13:35.182256 | controller -> localhost | changed: "/var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/artifacts" 2026-01-08 00:13:35.397892 | controller -> localhost | changed: "/var/lib/zuul/builds/71e60d410f534d13a17c0484a2b918b3/work/docs" 2026-01-08 00:13:35.417057 | 2026-01-08 00:13:35.417198 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-08 00:13:36.132300 | controller | changed: 2026-01-08 00:13:36.132525 | controller | .d..t...... ./ 2026-01-08 00:13:36.132563 | controller | cd+++++++++ controller/ 2026-01-08 00:13:36.132610 | controller | changed: All items complete 2026-01-08 00:13:36.132640 | 2026-01-08 00:13:36.612797 | controller | changed: .d..t...... ./ 2026-01-08 00:13:37.176610 | controller | changed: .d..t...... ./ 2026-01-08 00:13:37.197405 | 2026-01-08 00:13:37.197761 | TASK [include_role : fetch-output-openshift] 2026-01-08 00:13:37.223648 | controller | skipping: Conditional result was False 2026-01-08 00:13:37.237748 | 2026-01-08 00:13:37.237955 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-08 00:13:37.289656 | controller | skipping: Conditional result was False 2026-01-08 00:13:37.302465 | controller | skipping: Conditional result was False 2026-01-08 00:13:37.334371 | 2026-01-08 00:13:37.334479 | PLAY [localhost] 2026-01-08 00:13:37.347183 | 2026-01-08 00:13:37.347276 | TASK [Run Zuul manifest role] 2026-01-08 00:13:37.365931 | localhost | ok 2026-01-08 00:13:37.382092 | 2026-01-08 00:13:37.382226 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-08 00:13:37.768633 | localhost | changed 2026-01-08 00:13:37.775063 | 2026-01-08 00:13:37.775170 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-08 00:13:37.815346 | localhost | ok 2026-01-08 00:13:37.827930 | 2026-01-08 00:13:37.828065 | TASK [Set zuul-log-path fact] 2026-01-08 00:13:37.846801 | localhost | ok 2026-01-08 00:13:37.861796 | 2026-01-08 00:13:37.861917 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-08 00:13:37.891876 | localhost | ok 2026-01-08 00:13:37.901597 | 2026-01-08 00:13:37.901747 | LOOP [Run upload-logs-swift role] 2026-01-08 00:13:37.937591 | localhost | Output suppressed because no_log was given 2026-01-08 00:13:37.963903 | 2026-01-08 00:13:37.964018 | TASK [Set zuul-log-path fact] 2026-01-08 00:13:37.987822 | localhost | skipping: Conditional result was False 2026-01-08 00:13:37.994636 | 2026-01-08 00:13:37.994767 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-08 00:13:38.466493 | localhost -> localhost | ok: Runtime: 0:00:00.014068 2026-01-08 00:13:38.518390 | 2026-01-08 00:13:38.518511 | TASK [upload-logs-swift : Upload logs to swift]