2026-02-16 00:26:29.435085 | Job console starting... 2026-02-16 00:26:29.446904 | Updating repositories 2026-02-16 00:26:29.600699 | Preparing job workspace 2026-02-16 00:26:33.195595 | Running Ansible setup... 2026-02-16 00:26:42.661813 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-16 00:26:43.325362 | 2026-02-16 00:26:43.325489 | PLAY [localhost] 2026-02-16 00:26:43.334263 | 2026-02-16 00:26:43.334356 | TASK [Gathering Facts] 2026-02-16 00:26:44.309903 | localhost | ok 2026-02-16 00:26:44.335037 | 2026-02-16 00:26:44.335212 | TASK [Setup log path fact] 2026-02-16 00:26:44.356482 | localhost | ok 2026-02-16 00:26:44.369564 | 2026-02-16 00:26:44.369680 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-16 00:26:44.408076 | localhost | ok 2026-02-16 00:26:44.415787 | 2026-02-16 00:26:44.415893 | TASK [emit-job-header : Print job information] 2026-02-16 00:26:44.469042 | # Job Information 2026-02-16 00:26:44.469306 | Ansible Version: 2.15.12 2026-02-16 00:26:44.469372 | Job: ansible-test-sanity-docker-milestone 2026-02-16 00:26:44.469419 | Pipeline: periodic 2026-02-16 00:26:44.469461 | Executor: ze03.softwarefactory-project.io 2026-02-16 00:26:44.469501 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-16 00:26:44.469554 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/784/ansible/784c106fc98347c087d1fabdbd1a3308/ 2026-02-16 00:26:44.469595 | Event ID: 61af5ebc0dcf4552bcee9529f5d1db1b 2026-02-16 00:26:44.480029 | 2026-02-16 00:26:44.480247 | LOOP [emit-job-header : Print node information] 2026-02-16 00:26:44.605018 | localhost | ok: 2026-02-16 00:26:44.605410 | localhost | # Node Information 2026-02-16 00:26:44.605524 | localhost | Inventory Hostname: controller 2026-02-16 00:26:44.605620 | localhost | Hostname: np0005620542 2026-02-16 00:26:44.605714 | localhost | Username: zuul 2026-02-16 00:26:44.606057 | localhost | Distro: Fedora 37 2026-02-16 00:26:44.606159 | localhost | Provider: ansible-vexxhost-ams1 2026-02-16 00:26:44.606231 | localhost | Region: ams1 2026-02-16 00:26:44.606299 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-16 00:26:44.606369 | localhost | Product Name: OpenStack Nova 2026-02-16 00:26:44.606436 | localhost | Interface IP: 38.129.16.18 2026-02-16 00:26:44.634539 | 2026-02-16 00:26:44.634855 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-16 00:26:45.078809 | localhost -> localhost | changed 2026-02-16 00:26:45.084448 | 2026-02-16 00:26:45.084520 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-16 00:26:45.969646 | localhost -> localhost | changed 2026-02-16 00:26:45.990174 | 2026-02-16 00:26:45.990270 | PLAY [all:!appliance*] 2026-02-16 00:26:46.006541 | 2026-02-16 00:26:46.006624 | TASK [include_role : start-zuul-console] 2026-02-16 00:26:46.026081 | controller | ok 2026-02-16 00:26:46.041259 | 2026-02-16 00:26:46.041359 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-16 00:26:47.118437 | controller | ok 2026-02-16 00:26:47.148596 | 2026-02-16 00:26:47.148764 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-16 00:26:50.652876 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-16 00:26:50.666978 | 2026-02-16 00:26:50.667142 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-16 00:26:51.038849 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.048489 | 2026-02-16 00:26:51.048605 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-16 00:26:51.073281 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.082322 | 2026-02-16 00:26:51.082445 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-16 00:26:51.110191 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.126695 | 2026-02-16 00:26:51.126985 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-16 00:26:51.153105 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.163017 | 2026-02-16 00:26:51.163189 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-16 00:26:51.189840 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.200584 | 2026-02-16 00:26:51.200786 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-16 00:26:51.229345 | controller | skipping: Conditional result was False 2026-02-16 00:26:51.252719 | 2026-02-16 00:26:51.252894 | TASK [Disable Fedora Modular] 2026-02-16 00:26:52.430600 | controller | changed 2026-02-16 00:26:52.443194 | 2026-02-16 00:26:52.443331 | TASK [Enable EPEL] 2026-02-16 00:26:52.470423 | controller | skipping: Conditional result was False 2026-02-16 00:26:52.484040 | 2026-02-16 00:26:52.484223 | TASK [Register the RHEL node] 2026-02-16 00:26:52.885298 | 2026-02-16 00:26:52.885578 | TASK [Show the subscription-manager status] 2026-02-16 00:26:53.276116 | controller | skipping: Conditional result was False 2026-02-16 00:26:53.290405 | 2026-02-16 00:26:53.290579 | TASK [Enable EPEL on RHEL] 2026-02-16 00:26:53.676541 | controller | skipping: Conditional result was False 2026-02-16 00:26:53.689837 | 2026-02-16 00:26:53.690007 | TASK [Install git and tox] 2026-02-16 00:29:01.920670 | controller | changed 2026-02-16 00:29:01.931693 | 2026-02-16 00:29:01.932487 | TASK [include_role : prepare-workspace] 2026-02-16 00:29:01.974653 | controller | ok 2026-02-16 00:29:02.010702 | 2026-02-16 00:29:02.010859 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-16 00:29:02.837470 | controller | ok 2026-02-16 00:29:02.843717 | 2026-02-16 00:29:02.843828 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-16 00:29:19.133687 | controller | Output suppressed because no_log was given 2026-02-16 00:29:19.152664 | 2026-02-16 00:29:19.152836 | TASK [include_role : prepare-workspace-openshift] 2026-02-16 00:29:19.172637 | controller | skipping: Conditional result was False 2026-02-16 00:29:19.224219 | 2026-02-16 00:29:19.224441 | PLAY [all:!appliance] 2026-02-16 00:29:19.250199 | 2026-02-16 00:29:19.250404 | TASK [Run add-build-sshkey role (RSA)] 2026-02-16 00:29:19.286016 | controller | ok 2026-02-16 00:29:19.310771 | 2026-02-16 00:29:19.310968 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-16 00:29:19.645875 | controller -> localhost | ok 2026-02-16 00:29:19.652637 | 2026-02-16 00:29:19.652713 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-16 00:29:19.685079 | controller | ok 2026-02-16 00:29:19.699020 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-16 00:29:19.706119 | 2026-02-16 00:29:19.706189 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-16 00:29:20.292207 | controller -> localhost | Generating public/private rsa key pair. 2026-02-16 00:29:20.292659 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_rsa. 2026-02-16 00:29:20.292801 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_rsa.pub. 2026-02-16 00:29:20.292926 | controller -> localhost | The key fingerprint is: 2026-02-16 00:29:20.293030 | controller -> localhost | SHA256:uQ0oC7FrOHq1uoBcAGOZQYcmtpCZK6o5Kqr4BctmuKI zuul-build-sshkey 2026-02-16 00:29:20.293142 | controller -> localhost | The key's randomart image is: 2026-02-16 00:29:20.293207 | controller -> localhost | +---[RSA 2048]----+ 2026-02-16 00:29:20.293257 | controller -> localhost | |+B=. | 2026-02-16 00:29:20.293306 | controller -> localhost | |OB. | 2026-02-16 00:29:20.293355 | controller -> localhost | |=oo | 2026-02-16 00:29:20.293419 | controller -> localhost | |o..o . . | 2026-02-16 00:29:20.293499 | controller -> localhost | |o +.. . S | 2026-02-16 00:29:20.293594 | controller -> localhost | |++.=.o + | 2026-02-16 00:29:20.293697 | controller -> localhost | |BoB.o. . . | 2026-02-16 00:29:20.293792 | controller -> localhost | |OB... | 2026-02-16 00:29:20.293846 | controller -> localhost | |E++o | 2026-02-16 00:29:20.293898 | controller -> localhost | +----[SHA256]-----+ 2026-02-16 00:29:20.294078 | controller -> localhost | ok: Runtime: 0:00:00.124416 2026-02-16 00:29:20.311590 | 2026-02-16 00:29:20.311811 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-16 00:29:20.353054 | controller | ok 2026-02-16 00:29:20.375941 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-16 00:29:20.392293 | 2026-02-16 00:29:20.392432 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-16 00:29:20.418999 | controller | skipping: Conditional result was False 2026-02-16 00:29:20.430528 | 2026-02-16 00:29:20.430666 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-16 00:29:21.678612 | controller | changed 2026-02-16 00:29:21.692556 | 2026-02-16 00:29:21.692788 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-16 00:29:22.459520 | controller | ok 2026-02-16 00:29:22.474517 | 2026-02-16 00:29:22.474804 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-16 00:29:25.737331 | controller | changed 2026-02-16 00:29:25.750523 | 2026-02-16 00:29:25.750679 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-16 00:29:29.030761 | controller | changed 2026-02-16 00:29:29.043047 | 2026-02-16 00:29:29.043187 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-16 00:29:29.070862 | controller | skipping: Conditional result was False 2026-02-16 00:29:29.085021 | 2026-02-16 00:29:29.085192 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-16 00:29:29.532660 | controller -> localhost | changed 2026-02-16 00:29:29.560216 | 2026-02-16 00:29:29.560388 | TASK [add-build-sshkey : Add back temp key] 2026-02-16 00:29:29.862747 | controller -> localhost | Identity added: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_rsa (zuul-build-sshkey) 2026-02-16 00:29:29.863059 | controller -> localhost | ok: Runtime: 0:00:00.009484 2026-02-16 00:29:29.873097 | 2026-02-16 00:29:29.873197 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-16 00:29:30.816379 | controller | ok 2026-02-16 00:29:30.830760 | 2026-02-16 00:29:30.830926 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-16 00:29:30.871084 | controller | skipping: Conditional result was False 2026-02-16 00:29:30.901114 | 2026-02-16 00:29:30.901295 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-16 00:29:30.938296 | controller | ok 2026-02-16 00:29:30.962838 | 2026-02-16 00:29:30.962961 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-16 00:29:31.265719 | controller -> localhost | ok 2026-02-16 00:29:31.279487 | 2026-02-16 00:29:31.279652 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-16 00:29:31.322301 | controller | ok 2026-02-16 00:29:31.345753 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-16 00:29:31.355076 | 2026-02-16 00:29:31.355189 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-16 00:29:31.717010 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-16 00:29:31.717368 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_ecdsa. 2026-02-16 00:29:31.717431 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_ecdsa.pub. 2026-02-16 00:29:31.717491 | controller -> localhost | The key fingerprint is: 2026-02-16 00:29:31.717535 | controller -> localhost | SHA256:4LHvi321pSdi+LEoagHBQtTx0ltr9Ljv14JESR+ub6s zuul-build-sshkey 2026-02-16 00:29:31.717575 | controller -> localhost | The key's randomart image is: 2026-02-16 00:29:31.717616 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-16 00:29:31.717655 | controller -> localhost | |o+... | 2026-02-16 00:29:31.717694 | controller -> localhost | |. o.o . . | 2026-02-16 00:29:31.717761 | controller -> localhost | | . o ooo. + . | 2026-02-16 00:29:31.717810 | controller -> localhost | | . ..+++o o | 2026-02-16 00:29:31.717849 | controller -> localhost | | . .o+S.. | 2026-02-16 00:29:31.717888 | controller -> localhost | | . ...o . . | 2026-02-16 00:29:31.717925 | controller -> localhost | | . .o.+..+ | 2026-02-16 00:29:31.717963 | controller -> localhost | | . .+oo+B+.. | 2026-02-16 00:29:31.718000 | controller -> localhost | | .....*E*ooo | 2026-02-16 00:29:31.718039 | controller -> localhost | +----[SHA256]-----+ 2026-02-16 00:29:31.718133 | controller -> localhost | ok: Runtime: 0:00:00.014506 2026-02-16 00:29:31.732384 | 2026-02-16 00:29:31.732544 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-16 00:29:31.772705 | controller | ok 2026-02-16 00:29:31.790972 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-16 00:29:31.840400 | 2026-02-16 00:29:31.840533 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-16 00:29:31.865375 | controller | skipping: Conditional result was False 2026-02-16 00:29:31.872884 | 2026-02-16 00:29:31.872968 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-16 00:29:32.963462 | controller | changed 2026-02-16 00:29:32.985088 | 2026-02-16 00:29:32.985262 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-16 00:29:33.792286 | controller | ok 2026-02-16 00:29:33.808954 | 2026-02-16 00:29:33.809107 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-16 00:29:37.075577 | controller | changed 2026-02-16 00:29:37.088562 | 2026-02-16 00:29:37.088673 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-16 00:29:40.394504 | controller | changed 2026-02-16 00:29:40.411868 | 2026-02-16 00:29:40.412107 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-16 00:29:40.441360 | controller | skipping: Conditional result was False 2026-02-16 00:29:40.451528 | 2026-02-16 00:29:40.451671 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-16 00:29:40.755884 | controller -> localhost | changed 2026-02-16 00:29:40.771620 | 2026-02-16 00:29:40.771715 | TASK [add-build-sshkey : Add back temp key] 2026-02-16 00:29:41.046490 | controller -> localhost | Identity added: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/784c106fc98347c087d1fabdbd1a3308_id_ecdsa (zuul-build-sshkey) 2026-02-16 00:29:41.046769 | controller -> localhost | ok: Runtime: 0:00:00.009863 2026-02-16 00:29:41.059474 | 2026-02-16 00:29:41.059620 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-16 00:29:41.843069 | controller | ok 2026-02-16 00:29:41.859842 | 2026-02-16 00:29:41.860032 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-16 00:29:41.889627 | controller | skipping: Conditional result was False 2026-02-16 00:29:41.912497 | 2026-02-16 00:29:41.912640 | TASK [include_role : remove-zuul-sshkey] 2026-02-16 00:29:41.927904 | controller | skipping: Conditional result was False 2026-02-16 00:29:41.936997 | 2026-02-16 00:29:41.937103 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-16 00:29:42.688455 | controller | ok: "logs" 2026-02-16 00:29:42.689085 | controller | ok: All items complete 2026-02-16 00:29:42.689187 | 2026-02-16 00:29:43.394240 | controller | ok: "artifacts" 2026-02-16 00:29:44.109926 | controller | ok: "docs" 2026-02-16 00:29:44.123323 | 2026-02-16 00:29:44.123454 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-16 00:29:44.846605 | controller | changed: "logs" 2026-02-16 00:29:45.586226 | controller | changed: "artifacts" 2026-02-16 00:29:46.257145 | controller | changed: "docs" 2026-02-16 00:29:46.310008 | 2026-02-16 00:29:46.310143 | PLAY RECAP 2026-02-16 00:29:46.310218 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-16 00:29:46.310267 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-16 00:29:46.310305 | 2026-02-16 00:29:46.435753 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-16 00:29:46.437372 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-16 00:29:46.990901 | 2026-02-16 00:29:46.991012 | PLAY [all] 2026-02-16 00:29:47.012984 | 2026-02-16 00:29:47.013148 | TASK [Install binary dependencies] 2026-02-16 00:29:47.074878 | controller | ok 2026-02-16 00:29:47.099340 | 2026-02-16 00:29:47.099488 | TASK [bindep : Include find tasks] 2026-02-16 00:29:47.142238 | controller | ok 2026-02-16 00:29:47.153816 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-16 00:29:47.160771 | 2026-02-16 00:29:47.160846 | TASK [bindep : Look for bindep.txt] 2026-02-16 00:29:48.154801 | controller | ok 2026-02-16 00:29:48.167610 | 2026-02-16 00:29:48.167761 | TASK [bindep : Define bindep_file fact] 2026-02-16 00:29:48.183223 | controller | skipping: Conditional result was False 2026-02-16 00:29:48.193836 | 2026-02-16 00:29:48.193985 | TASK [bindep : Look for other-requirements.txt] 2026-02-16 00:29:48.872229 | controller | ok 2026-02-16 00:29:48.888132 | 2026-02-16 00:29:48.888432 | TASK [bindep : Define bindep_file fact] 2026-02-16 00:29:48.916752 | controller | skipping: Conditional result was False 2026-02-16 00:29:48.926234 | 2026-02-16 00:29:48.926371 | TASK [bindep : Look for bindep fallback file] 2026-02-16 00:29:48.952505 | controller | skipping: Conditional result was False 2026-02-16 00:29:48.962457 | 2026-02-16 00:29:48.962575 | TASK [bindep : Define bindep_file fact] 2026-02-16 00:29:48.987699 | controller | skipping: Conditional result was False 2026-02-16 00:29:48.997285 | 2026-02-16 00:29:48.997377 | TASK [bindep : Include bindep tasks] 2026-02-16 00:29:49.023875 | controller | skipping: Conditional result was False 2026-02-16 00:29:49.033106 | 2026-02-16 00:29:49.033207 | TASK [bindep : Include install tasks] 2026-02-16 00:29:49.068842 | controller | skipping: Conditional result was False 2026-02-16 00:29:49.079982 | 2026-02-16 00:29:49.080111 | LOOP [bindep : Include package tasks] 2026-02-16 00:29:49.157561 | 2026-02-16 00:29:49.157750 | TASK [Run test-setup role] 2026-02-16 00:29:49.179481 | controller | ok 2026-02-16 00:29:49.196174 | 2026-02-16 00:29:49.196246 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-16 00:29:49.927210 | controller | ok 2026-02-16 00:29:49.940409 | 2026-02-16 00:29:49.940572 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-16 00:29:50.310494 | controller | skipping: Conditional result was False 2026-02-16 00:29:50.362285 | 2026-02-16 00:29:50.362387 | PLAY RECAP 2026-02-16 00:29:50.362444 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-16 00:29:50.362477 | 2026-02-16 00:29:50.471315 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-16 00:29:50.473174 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-16 00:29:51.090198 | 2026-02-16 00:29:51.090325 | PLAY [controller] 2026-02-16 00:29:51.111931 | 2026-02-16 00:29:51.112089 | TASK [Create the /root directory] 2026-02-16 00:29:52.147447 | controller | ok 2026-02-16 00:29:52.162484 | 2026-02-16 00:29:52.162672 | TASK [Install glibc-langpack-en] 2026-02-16 00:30:00.569327 | controller | ok: Nothing to do 2026-02-16 00:30:00.583070 | 2026-02-16 00:30:00.583212 | TASK [Ensure controller directory exists] 2026-02-16 00:30:01.513959 | controller | changed 2026-02-16 00:30:01.531050 | 2026-02-16 00:30:01.531231 | TASK [Install container runtime] 2026-02-16 00:30:01.600004 | controller | ok 2026-02-16 00:30:01.653776 | 2026-02-16 00:30:01.653931 | LOOP [ensure-podman : Find distribution installation] 2026-02-16 00:30:01.696781 | controller | ok: "/var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-16 00:30:01.716407 | controller | included: /var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-16 00:30:01.733532 | 2026-02-16 00:30:01.733775 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-16 00:32:01.989295 | controller | changed 2026-02-16 00:32:01.995793 | 2026-02-16 00:32:01.995900 | TASK [ensure-podman : Fetch podman version] 2026-02-16 00:32:03.210467 | controller | Client: Podman Engine 2026-02-16 00:32:03.251720 | controller | Version: 4.6.2 2026-02-16 00:32:03.251804 | controller | API Version: 4.6.2 2026-02-16 00:32:03.251814 | controller | Go Version: go1.19.12 2026-02-16 00:32:03.251843 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-16 00:32:03.251853 | controller | OS/Arch: linux/amd64 2026-02-16 00:32:03.859801 | controller | ok: Runtime: 0:00:00.323778 2026-02-16 00:32:03.866692 | 2026-02-16 00:32:03.866791 | TASK [ensure-podman : Print podman version installed] 2026-02-16 00:32:03.901712 | Podman version: Client: Podman Engine 2026-02-16 00:32:03.901914 | Version: 4.6.2 2026-02-16 00:32:03.901945 | API Version: 4.6.2 2026-02-16 00:32:03.901967 | Go Version: go1.19.12 2026-02-16 00:32:03.901987 | Built: Mon Aug 28 19:38:31 2023 2026-02-16 00:32:03.902007 | OS/Arch: linux/amd64 2026-02-16 00:32:03.908053 | 2026-02-16 00:32:03.908146 | TASK [ensure-podman : Validate podman engine] 2026-02-16 00:32:04.265821 | controller | skipping: Conditional result was False 2026-02-16 00:32:04.280130 | 2026-02-16 00:32:04.280296 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-16 00:32:04.307521 | controller | skipping: Conditional result was False 2026-02-16 00:32:04.331422 | 2026-02-16 00:32:04.331585 | TASK [Ensure python3.8 is present] 2026-02-16 00:32:04.359045 | controller | skipping: Conditional result was False 2026-02-16 00:32:04.372620 | 2026-02-16 00:32:04.372862 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-16 00:32:04.402004 | controller | ok 2026-02-16 00:32:04.438179 | 2026-02-16 00:32:04.438351 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-16 00:32:07.709658 | controller | ok: Nothing to do 2026-02-16 00:32:07.715212 | 2026-02-16 00:32:07.715279 | TASK [our-ensure-python : Also install python3-devel] 2026-02-16 00:32:22.853672 | controller | changed 2026-02-16 00:32:22.878907 | 2026-02-16 00:32:22.879134 | TASK [Run ensure-virtualenv role] 2026-02-16 00:32:22.939958 | controller | ok 2026-02-16 00:32:22.960904 | 2026-02-16 00:32:22.961020 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-16 00:32:23.744016 | controller | /usr/bin/virtualenv 2026-02-16 00:32:24.314892 | controller | ok: Runtime: 0:00:00.006390 2026-02-16 00:32:24.332285 | 2026-02-16 00:32:24.332447 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-16 00:32:24.357107 | controller | skipping: Conditional result was False 2026-02-16 00:32:24.357518 | controller | ok: All items complete 2026-02-16 00:32:24.357551 | 2026-02-16 00:32:24.376476 | 2026-02-16 00:32:24.376646 | TASK [Find the full path of the Python interpreter] 2026-02-16 00:32:25.192724 | controller | /usr/bin/python3 2026-02-16 00:32:25.741529 | controller | ok 2026-02-16 00:32:25.754828 | 2026-02-16 00:32:25.755110 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-16 00:32:27.597747 | controller | created virtual environment CPython3.11.0.final.0-64 in 860ms 2026-02-16 00:32:27.687317 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-16 00:32:27.687403 | 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-02-16 00:32:27.687421 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-16 00:32:27.687447 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-16 00:32:28.159150 | controller | changed 2026-02-16 00:32:28.168341 | 2026-02-16 00:32:28.168450 | TASK [Set selinux package] 2026-02-16 00:32:28.202706 | controller | ok 2026-02-16 00:32:28.210738 | 2026-02-16 00:32:28.210863 | TASK [Set selinux package (Fedora)] 2026-02-16 00:32:28.262482 | controller | ok 2026-02-16 00:32:28.268972 | 2026-02-16 00:32:28.269036 | TASK [Install selinux into virtualenv] 2026-02-16 00:32:31.722829 | controller | Collecting selinux-please-lie-to-me 2026-02-16 00:32:31.793235 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-16 00:32:32.375596 | controller | Collecting setuptools<50.0.0 2026-02-16 00:32:32.381757 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-16 00:32:32.441326 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 14.7 MB/s eta 0:00:00 2026-02-16 00:32:32.587418 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-16 00:32:32.587784 | controller | Attempting uninstall: setuptools 2026-02-16 00:32:32.591662 | controller | Found existing installation: setuptools 62.6.0 2026-02-16 00:32:32.697787 | controller | Uninstalling setuptools-62.6.0: 2026-02-16 00:32:32.712523 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-16 00:32:33.467956 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-16 00:32:33.667132 | controller | 2026-02-16 00:32:33.943408 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-16 00:32:33.943463 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-16 00:32:34.148977 | controller | ok: Runtime: 0:00:04.820646 2026-02-16 00:32:34.154992 | 2026-02-16 00:32:34.155090 | TASK [Install pytest-forked into virtualenv] 2026-02-16 00:32:35.690972 | controller | Collecting pytest-forked 2026-02-16 00:32:35.749655 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-16 00:32:35.804359 | controller | Collecting py 2026-02-16 00:32:35.812387 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-16 00:32:35.839956 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.1 MB/s eta 0:00:00 2026-02-16 00:32:36.063959 | controller | Collecting pytest>=3.10 2026-02-16 00:32:36.071493 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-16 00:32:36.098307 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 17.2 MB/s eta 0:00:00 2026-02-16 00:32:36.151006 | controller | Collecting iniconfig>=1.0.1 2026-02-16 00:32:36.156158 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-16 00:32:36.224402 | controller | Collecting packaging>=22 2026-02-16 00:32:36.229752 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-16 00:32:36.241521 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 7.5 MB/s eta 0:00:00 2026-02-16 00:32:36.300323 | controller | Collecting pluggy<2,>=1.5 2026-02-16 00:32:36.305369 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-16 00:32:36.378181 | controller | Collecting pygments>=2.7.2 2026-02-16 00:32:36.383743 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-16 00:32:36.418966 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 44.2 MB/s eta 0:00:00 2026-02-16 00:32:36.546842 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-16 00:32:38.978459 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-16 00:32:38.994310 | controller | 2026-02-16 00:32:39.216058 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-16 00:32:39.216109 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-16 00:32:39.561869 | controller | ok: Runtime: 0:00:04.209387 2026-02-16 00:32:39.567836 | 2026-02-16 00:32:39.567902 | TASK [Update pip] 2026-02-16 00:32:40.924404 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-16 00:32:41.221145 | controller | Collecting pip 2026-02-16 00:32:41.294643 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-16 00:32:41.381935 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 21.7 MB/s eta 0:00:00 2026-02-16 00:32:41.550604 | controller | Installing collected packages: pip 2026-02-16 00:32:41.552689 | controller | Attempting uninstall: pip 2026-02-16 00:32:41.556969 | controller | Found existing installation: pip 22.2.2 2026-02-16 00:32:41.874164 | controller | Uninstalling pip-22.2.2: 2026-02-16 00:32:41.910224 | controller | Successfully uninstalled pip-22.2.2 2026-02-16 00:32:43.922821 | controller | Successfully installed pip-26.0.1 2026-02-16 00:32:44.440838 | controller | ok: Runtime: 0:00:03.807632 2026-02-16 00:32:44.453400 | 2026-02-16 00:32:44.453867 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-16 00:32:45.463904 | controller | changed 2026-02-16 00:32:45.478563 | 2026-02-16 00:32:45.478812 | TASK [Install ansible into virtualenv] 2026-02-16 00:32:46.799308 | controller | Processing ./src/github.com/ansible/ansible 2026-02-16 00:32:46.803187 | controller | Installing build dependencies: started 2026-02-16 00:32:48.762789 | controller | Installing build dependencies: finished with status 'done' 2026-02-16 00:32:48.764044 | controller | Getting requirements to build wheel: started 2026-02-16 00:32:50.392882 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-16 00:32:50.394213 | controller | Preparing metadata (pyproject.toml): started 2026-02-16 00:32:51.276408 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-16 00:32:51.279938 | 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-02-16 00:32:51.286023 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-16 00:32:51.864305 | controller | ERROR 2026-02-16 00:32:51.864493 | controller | { 2026-02-16 00:32:51.864521 | controller | "delta": "0:00:05.275199", 2026-02-16 00:32:51.864541 | controller | "end": "2026-02-16 00:32:51.453108", 2026-02-16 00:32:51.864559 | controller | "msg": "non-zero return code", 2026-02-16 00:32:51.864587 | controller | "rc": 1, 2026-02-16 00:32:51.864605 | controller | "start": "2026-02-16 00:32:46.177909" 2026-02-16 00:32:51.864621 | controller | } failure 2026-02-16 00:32:51.866332 | 2026-02-16 00:32:51.866378 | PLAY RECAP 2026-02-16 00:32:51.866422 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-16 00:32:51.866442 | 2026-02-16 00:32:51.968192 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-16 00:32:51.970094 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-16 00:32:52.623794 | 2026-02-16 00:32:52.623968 | PLAY [all] 2026-02-16 00:32:52.647534 | 2026-02-16 00:32:52.647783 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-16 00:32:54.497992 | controller | changed: non-zero return code 2026-02-16 00:32:54.509566 | 2026-02-16 00:32:54.509907 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-16 00:32:54.539249 | controller | skipping: Conditional result was False 2026-02-16 00:32:54.553780 | 2026-02-16 00:32:54.553937 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-16 00:32:54.598011 | 2026-02-16 00:32:54.598330 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-16 00:32:54.642417 | 2026-02-16 00:32:54.642780 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-16 00:32:54.691515 | controller | skipping: Conditional result was False 2026-02-16 00:32:54.705301 | 2026-02-16 00:32:54.705482 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-16 00:32:54.745940 | 2026-02-16 00:32:54.746272 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-16 00:32:54.764115 | controller | skipping: Conditional result was False 2026-02-16 00:32:54.777716 | 2026-02-16 00:32:54.777892 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-16 00:32:54.795222 | controller | skipping: Conditional result was False 2026-02-16 00:32:54.804284 | 2026-02-16 00:32:54.804376 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-16 00:32:54.821787 | controller | skipping: Conditional result was False 2026-02-16 00:32:54.860611 | 2026-02-16 00:32:54.860866 | PLAY RECAP 2026-02-16 00:32:54.860930 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-16 00:32:54.860954 | 2026-02-16 00:32:55.020992 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-16 00:32:55.022220 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-16 00:32:55.631437 | 2026-02-16 00:32:55.631559 | PLAY [all:!appliance*] 2026-02-16 00:32:55.652875 | 2026-02-16 00:32:55.652968 | TASK [unregister the node] 2026-02-16 00:32:56.006679 | controller | skipping: Conditional result was False 2026-02-16 00:32:56.019302 | 2026-02-16 00:32:56.019509 | TASK [include_role : fetch-output] 2026-02-16 00:32:56.078198 | controller | ok 2026-02-16 00:32:56.116948 | 2026-02-16 00:32:56.117037 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-16 00:32:56.193249 | controller | skipping: Conditional result was False 2026-02-16 00:32:56.206243 | 2026-02-16 00:32:56.206384 | TASK [fetch-output : Set log path for single node] 2026-02-16 00:32:56.254748 | controller | ok 2026-02-16 00:32:56.266972 | 2026-02-16 00:32:56.267106 | LOOP [fetch-output : Ensure local output dirs] 2026-02-16 00:32:56.722538 | controller -> localhost | ok: "/var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/logs" 2026-02-16 00:32:56.945156 | controller -> localhost | changed: "/var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/artifacts" 2026-02-16 00:32:57.187505 | controller -> localhost | changed: "/var/lib/zuul/builds/784c106fc98347c087d1fabdbd1a3308/work/docs" 2026-02-16 00:32:57.213297 | 2026-02-16 00:32:57.213490 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-16 00:32:59.479980 | controller | changed: 2026-02-16 00:32:59.480493 | controller | .d..t...... ./ 2026-02-16 00:32:59.480542 | controller | cd+++++++++ controller/ 2026-02-16 00:32:59.480589 | controller | changed: All items complete 2026-02-16 00:32:59.480617 | 2026-02-16 00:33:01.590444 | controller | changed: .d..t...... ./ 2026-02-16 00:33:03.690982 | controller | changed: .d..t...... ./ 2026-02-16 00:33:03.722252 | 2026-02-16 00:33:03.722540 | TASK [include_role : fetch-output-openshift] 2026-02-16 00:33:03.750051 | controller | skipping: Conditional result was False 2026-02-16 00:33:03.766501 | 2026-02-16 00:33:03.766717 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-16 00:33:03.809155 | controller | skipping: Conditional result was False 2026-02-16 00:33:03.818705 | controller | skipping: Conditional result was False 2026-02-16 00:33:03.873711 | 2026-02-16 00:33:03.873884 | PLAY [localhost] 2026-02-16 00:33:03.891965 | 2026-02-16 00:33:03.892050 | TASK [Run Zuul manifest role] 2026-02-16 00:33:03.914159 | localhost | ok 2026-02-16 00:33:03.934018 | 2026-02-16 00:33:03.934110 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-16 00:33:04.350940 | localhost | changed 2026-02-16 00:33:04.355662 | 2026-02-16 00:33:04.355736 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-16 00:33:04.401814 | localhost | ok 2026-02-16 00:33:04.420472 | 2026-02-16 00:33:04.420552 | TASK [Set zuul-log-path fact] 2026-02-16 00:33:04.487568 | localhost | ok 2026-02-16 00:33:04.501689 | 2026-02-16 00:33:04.501778 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-16 00:33:04.533241 | localhost | ok 2026-02-16 00:33:04.541554 | 2026-02-16 00:33:04.541649 | LOOP [Run upload-logs-swift role] 2026-02-16 00:33:04.600272 | localhost | Output suppressed because no_log was given 2026-02-16 00:33:04.648085 | 2026-02-16 00:33:04.648293 | TASK [Set zuul-log-path fact] 2026-02-16 00:33:04.685823 | localhost | skipping: Conditional result was False 2026-02-16 00:33:04.694859 | 2026-02-16 00:33:04.695005 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-16 00:33:05.133433 | localhost -> localhost | ok: Runtime: 0:00:00.009877 2026-02-16 00:33:05.148974 | 2026-02-16 00:33:05.149193 | TASK [upload-logs-swift : Upload logs to swift]