2025-12-21 00:22:40.352974 | Job console starting...
2025-12-21 00:22:40.369010 | Updating repositories
2025-12-21 00:22:40.490834 | Preparing job workspace
2025-12-21 00:22:44.527049 | Running Ansible setup...
2025-12-21 00:22:49.540815 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-21 00:22:50.227880 | 
2025-12-21 00:22:50.228020 | PLAY [localhost]
2025-12-21 00:22:50.237110 | 
2025-12-21 00:22:50.237186 | TASK [Gathering Facts]
2025-12-21 00:22:52.336235 | localhost | ok
2025-12-21 00:22:52.365391 | 
2025-12-21 00:22:52.365508 | TASK [Setup log path fact]
2025-12-21 00:22:52.391868 | localhost | ok
2025-12-21 00:22:52.411395 | 
2025-12-21 00:22:52.411555 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-21 00:22:52.455407 | localhost | ok
2025-12-21 00:22:52.470054 | 
2025-12-21 00:22:52.470219 | TASK [emit-job-header : Print job information]
2025-12-21 00:22:52.523753 | # Job Information
2025-12-21 00:22:52.523975 | Ansible Version: 2.15.12
2025-12-21 00:22:52.524021 | Job: ansible-test-sanity-docker-devel
2025-12-21 00:22:52.524051 | Pipeline: periodic
2025-12-21 00:22:52.524077 | Executor: ze04.softwarefactory-project.io
2025-12-21 00:22:52.524103 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-21 00:22:52.524140 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/1d9/ansible/1d99e3d8dad64b5d8d9d19a879d40c9b/
2025-12-21 00:22:52.524178 | Event ID: 0af00ed07cf843cab66474a277299bb1
2025-12-21 00:22:52.530381 | 
2025-12-21 00:22:52.530477 | LOOP [emit-job-header : Print node information]
2025-12-21 00:22:52.659248 | localhost | ok:
2025-12-21 00:22:52.659457 | localhost | # Node Information
2025-12-21 00:22:52.659486 | localhost | Inventory Hostname: controller
2025-12-21 00:22:52.659507 | localhost | Hostname: np0005568096
2025-12-21 00:22:52.659526 | localhost | Username: zuul
2025-12-21 00:22:52.659549 | localhost | Distro: Fedora 37
2025-12-21 00:22:52.659568 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-21 00:22:52.659586 | localhost | Region: ca-ymq-1
2025-12-21 00:22:52.659603 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-21 00:22:52.659620 | localhost | Product Name: OpenStack Nova
2025-12-21 00:22:52.659638 | localhost | Interface IP: 162.253.55.12
2025-12-21 00:22:52.679530 | 
2025-12-21 00:22:52.679717 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-21 00:22:53.087963 | localhost -> localhost | changed
2025-12-21 00:22:53.096532 | 
2025-12-21 00:22:53.096624 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-21 00:22:54.088112 | localhost -> localhost | changed
2025-12-21 00:22:54.127034 | 
2025-12-21 00:22:54.127316 | PLAY [all:!appliance*]
2025-12-21 00:22:54.158406 | 
2025-12-21 00:22:54.158581 | TASK [include_role : start-zuul-console]
2025-12-21 00:22:54.186151 | controller | ok
2025-12-21 00:22:54.200137 | 
2025-12-21 00:22:54.200268 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-21 00:22:54.648331 | controller | ok
2025-12-21 00:22:54.675264 | 
2025-12-21 00:22:54.675427 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-21 00:23:17.051762 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-21 00:23:17.068988 | 
2025-12-21 00:23:17.069187 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-21 00:23:17.621575 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.637545 | 
2025-12-21 00:23:17.637779 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-21 00:23:17.666426 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.682372 | 
2025-12-21 00:23:17.682560 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-21 00:23:17.710807 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.726728 | 
2025-12-21 00:23:17.726886 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-21 00:23:17.756601 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.771514 | 
2025-12-21 00:23:17.771673 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-21 00:23:17.800518 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.818631 | 
2025-12-21 00:23:17.818905 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-21 00:23:17.838088 | controller | skipping: Conditional result was False
2025-12-21 00:23:17.865415 | 
2025-12-21 00:23:17.865591 | TASK [Disable Fedora Modular]
2025-12-21 00:23:18.253547 | controller | changed
2025-12-21 00:23:18.266472 | 
2025-12-21 00:23:18.266619 | TASK [Enable EPEL]
2025-12-21 00:23:18.304818 | controller | skipping: Conditional result was False
2025-12-21 00:23:18.318377 | 
2025-12-21 00:23:18.318521 | TASK [Register the RHEL node]
2025-12-21 00:23:18.884912 | 
2025-12-21 00:23:18.885249 | TASK [Show the subscription-manager status]
2025-12-21 00:23:19.449035 | controller | skipping: Conditional result was False
2025-12-21 00:23:19.464044 | 
2025-12-21 00:23:19.464210 | TASK [Enable EPEL on RHEL]
2025-12-21 00:23:20.032229 | controller | skipping: Conditional result was False
2025-12-21 00:23:20.047202 | 
2025-12-21 00:23:20.047358 | TASK [Install git and tox]
2025-12-21 00:24:16.641765 | controller | changed
2025-12-21 00:24:16.656583 | 
2025-12-21 00:24:16.656847 | TASK [include_role : prepare-workspace]
2025-12-21 00:24:16.701469 | controller | ok
2025-12-21 00:24:16.736062 | 
2025-12-21 00:24:16.736220 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-21 00:24:16.979096 | controller | ok
2025-12-21 00:24:16.996039 | 
2025-12-21 00:24:16.996246 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-21 00:24:29.196006 | controller | Output suppressed because no_log was given
2025-12-21 00:24:29.219936 | 
2025-12-21 00:24:29.220086 | TASK [include_role : prepare-workspace-openshift]
2025-12-21 00:24:29.246944 | controller | skipping: Conditional result was False
2025-12-21 00:24:29.283967 | 
2025-12-21 00:24:29.284070 | PLAY [all:!appliance]
2025-12-21 00:24:29.338033 | 
2025-12-21 00:24:29.338165 | TASK [Run add-build-sshkey role (RSA)]
2025-12-21 00:24:29.368218 | controller | ok
2025-12-21 00:24:29.382623 | 
2025-12-21 00:24:29.382713 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-21 00:24:29.671411 | controller -> localhost | ok
2025-12-21 00:24:29.678491 | 
2025-12-21 00:24:29.678566 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-21 00:24:29.719626 | controller | ok
2025-12-21 00:24:29.733472 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-21 00:24:29.739469 | 
2025-12-21 00:24:29.739532 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-21 00:24:30.406323 | controller -> localhost | Generating public/private rsa key pair.
2025-12-21 00:24:30.406834 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_rsa.
2025-12-21 00:24:30.406908 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_rsa.pub.
2025-12-21 00:24:30.406959 | controller -> localhost | The key fingerprint is:
2025-12-21 00:24:30.407006 | controller -> localhost | SHA256:JGYdqeb7J4RYjXH1smT16QZ6ssrvWPgaOeTZ+U+cKe4 zuul-build-sshkey
2025-12-21 00:24:30.407051 | controller -> localhost | The key's randomart image is:
2025-12-21 00:24:30.407093 | controller -> localhost | +---[RSA 2048]----+
2025-12-21 00:24:30.407137 | controller -> localhost | |        .o. .    |
2025-12-21 00:24:30.407182 | controller -> localhost | |      ..o. o . . |
2025-12-21 00:24:30.407225 | controller -> localhost | |      +*o + o o  |
2025-12-21 00:24:30.407266 | controller -> localhost | |     o=o.o + o   |
2025-12-21 00:24:30.407306 | controller -> localhost | |     = .S + . o  |
2025-12-21 00:24:30.407364 | controller -> localhost | |    . oo.= = o o |
2025-12-21 00:24:30.407417 | controller -> localhost | |       oB = . =  |
2025-12-21 00:24:30.407461 | controller -> localhost | |      ...B.o o   |
2025-12-21 00:24:30.407504 | controller -> localhost | |       .**+.E..  |
2025-12-21 00:24:30.407551 | controller -> localhost | +----[SHA256]-----+
2025-12-21 00:24:30.407662 | controller -> localhost | ok: Runtime: 0:00:00.200378
2025-12-21 00:24:30.422842 | 
2025-12-21 00:24:30.423004 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-21 00:24:30.475127 | controller | ok
2025-12-21 00:24:30.496040 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-21 00:24:30.508438 | 
2025-12-21 00:24:30.508531 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-21 00:24:30.543995 | controller | skipping: Conditional result was False
2025-12-21 00:24:30.553743 | 
2025-12-21 00:24:30.553865 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-21 00:24:31.020898 | controller | changed
2025-12-21 00:24:31.034602 | 
2025-12-21 00:24:31.034791 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-21 00:24:31.271999 | controller | ok
2025-12-21 00:24:31.294444 | 
2025-12-21 00:24:31.294625 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-21 00:24:31.955459 | controller | changed
2025-12-21 00:24:31.969027 | 
2025-12-21 00:24:31.969200 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-21 00:24:32.593649 | controller | changed
2025-12-21 00:24:32.600063 | 
2025-12-21 00:24:32.600156 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-21 00:24:32.634328 | controller | skipping: Conditional result was False
2025-12-21 00:24:32.641509 | 
2025-12-21 00:24:32.641585 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-21 00:24:33.113440 | controller -> localhost | changed
2025-12-21 00:24:33.126508 | 
2025-12-21 00:24:33.126642 | TASK [add-build-sshkey : Add back temp key]
2025-12-21 00:24:33.428828 | controller -> localhost | Identity added: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_rsa (zuul-build-sshkey)
2025-12-21 00:24:33.429188 | controller -> localhost | ok: Runtime: 0:00:00.009898
2025-12-21 00:24:33.443847 | 
2025-12-21 00:24:33.444012 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-21 00:24:33.815041 | controller | ok
2025-12-21 00:24:33.826101 | 
2025-12-21 00:24:33.826294 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-21 00:24:33.864799 | controller | skipping: Conditional result was False
2025-12-21 00:24:33.889889 | 
2025-12-21 00:24:33.890105 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-21 00:24:33.932846 | controller | ok
2025-12-21 00:24:33.962125 | 
2025-12-21 00:24:33.962284 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-21 00:24:34.274267 | controller -> localhost | ok
2025-12-21 00:24:34.288248 | 
2025-12-21 00:24:34.288388 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-21 00:24:34.328005 | controller | ok
2025-12-21 00:24:34.347312 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-21 00:24:34.357714 | 
2025-12-21 00:24:34.357806 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-21 00:24:34.699296 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-21 00:24:34.699743 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_ecdsa.
2025-12-21 00:24:34.699814 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_ecdsa.pub.
2025-12-21 00:24:34.699879 | controller -> localhost | The key fingerprint is:
2025-12-21 00:24:34.699924 | controller -> localhost | SHA256:o9h4deXuH+7S+Re3MK+rE8nid1puHUKEgbuVkUaKk40 zuul-build-sshkey
2025-12-21 00:24:34.699967 | controller -> localhost | The key's randomart image is:
2025-12-21 00:24:34.700009 | controller -> localhost | +---[ECDSA 521]---+
2025-12-21 00:24:34.700050 | controller -> localhost | |          oo+    |
2025-12-21 00:24:34.700098 | controller -> localhost | |        =..= .   |
2025-12-21 00:24:34.700157 | controller -> localhost | |       E oo =    |
2025-12-21 00:24:34.700209 | controller -> localhost | |        .. = .   |
2025-12-21 00:24:34.700250 | controller -> localhost | |        S = +    |
2025-12-21 00:24:34.700289 | controller -> localhost | |     + o = = + o.|
2025-12-21 00:24:34.700328 | controller -> localhost | |    o + . . ooB.=|
2025-12-21 00:24:34.700368 | controller -> localhost | |     .   . +++o=.|
2025-12-21 00:24:34.700406 | controller -> localhost | |          .oBB*.o|
2025-12-21 00:24:34.700445 | controller -> localhost | +----[SHA256]-----+
2025-12-21 00:24:34.700530 | controller -> localhost | ok: Runtime: 0:00:00.015725
2025-12-21 00:24:34.714791 | 
2025-12-21 00:24:34.714932 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-21 00:24:34.757046 | controller | ok
2025-12-21 00:24:34.775106 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-21 00:24:34.791219 | 
2025-12-21 00:24:34.791330 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-21 00:24:34.818114 | controller | skipping: Conditional result was False
2025-12-21 00:24:34.829672 | 
2025-12-21 00:24:34.829788 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-21 00:24:35.124159 | controller | changed
2025-12-21 00:24:35.138276 | 
2025-12-21 00:24:35.138453 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-21 00:24:35.370134 | controller | ok
2025-12-21 00:24:35.378179 | 
2025-12-21 00:24:35.378287 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-21 00:24:36.009658 | controller | changed
2025-12-21 00:24:36.022051 | 
2025-12-21 00:24:36.022207 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-21 00:24:36.627909 | controller | changed
2025-12-21 00:24:36.636577 | 
2025-12-21 00:24:36.636777 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-21 00:24:36.674207 | controller | skipping: Conditional result was False
2025-12-21 00:24:36.681767 | 
2025-12-21 00:24:36.681846 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-21 00:24:37.003781 | controller -> localhost | changed
2025-12-21 00:24:37.034391 | 
2025-12-21 00:24:37.034574 | TASK [add-build-sshkey : Add back temp key]
2025-12-21 00:24:37.356117 | controller -> localhost | Identity added: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/1d99e3d8dad64b5d8d9d19a879d40c9b_id_ecdsa (zuul-build-sshkey)
2025-12-21 00:24:37.356416 | controller -> localhost | ok: Runtime: 0:00:00.013433
2025-12-21 00:24:37.363857 | 
2025-12-21 00:24:37.363922 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-21 00:24:37.567560 | controller | ok
2025-12-21 00:24:37.576399 | 
2025-12-21 00:24:37.576535 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-21 00:24:37.613510 | controller | skipping: Conditional result was False
2025-12-21 00:24:37.675030 | 
2025-12-21 00:24:37.675164 | TASK [include_role : remove-zuul-sshkey]
2025-12-21 00:24:37.700881 | controller | skipping: Conditional result was False
2025-12-21 00:24:37.707902 | 
2025-12-21 00:24:37.707972 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-21 00:24:37.946409 | controller | ok: "logs"
2025-12-21 00:24:37.946811 | controller | ok: All items complete
2025-12-21 00:24:37.946860 | 
2025-12-21 00:24:38.135922 | controller | ok: "artifacts"
2025-12-21 00:24:38.331219 | controller | ok: "docs"
2025-12-21 00:24:38.354660 | 
2025-12-21 00:24:38.354989 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-21 00:24:38.604505 | controller | changed: "logs"
2025-12-21 00:24:38.793210 | controller | changed: "artifacts"
2025-12-21 00:24:39.481445 | controller | changed: "docs"
2025-12-21 00:24:39.548084 | 
2025-12-21 00:24:39.548224 | PLAY RECAP
2025-12-21 00:24:39.548286 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-21 00:24:39.548326 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-21 00:24:39.548352 | 
2025-12-21 00:24:39.700418 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-21 00:24:39.702341 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-21 00:24:40.362074 | 
2025-12-21 00:24:40.362209 | PLAY [all]
2025-12-21 00:24:40.384787 | 
2025-12-21 00:24:40.384919 | TASK [Install binary dependencies]
2025-12-21 00:24:40.447831 | controller | ok
2025-12-21 00:24:40.476962 | 
2025-12-21 00:24:40.477177 | TASK [bindep : Include find tasks]
2025-12-21 00:24:40.510858 | controller | ok
2025-12-21 00:24:40.521720 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-21 00:24:40.530365 | 
2025-12-21 00:24:40.530462 | TASK [bindep : Look for bindep.txt]
2025-12-21 00:24:40.925191 | controller | ok
2025-12-21 00:24:40.937961 | 
2025-12-21 00:24:40.938120 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:24:40.955208 | controller | skipping: Conditional result was False
2025-12-21 00:24:40.969343 | 
2025-12-21 00:24:40.969498 | TASK [bindep : Look for other-requirements.txt]
2025-12-21 00:24:41.196934 | controller | ok
2025-12-21 00:24:41.205101 | 
2025-12-21 00:24:41.205189 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:24:41.242227 | controller | skipping: Conditional result was False
2025-12-21 00:24:41.250580 | 
2025-12-21 00:24:41.250697 | TASK [bindep : Look for bindep fallback file]
2025-12-21 00:24:41.285525 | controller | skipping: Conditional result was False
2025-12-21 00:24:41.294980 | 
2025-12-21 00:24:41.295097 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:24:41.319747 | controller | skipping: Conditional result was False
2025-12-21 00:24:41.328075 | 
2025-12-21 00:24:41.328181 | TASK [bindep : Include bindep tasks]
2025-12-21 00:24:41.352795 | controller | skipping: Conditional result was False
2025-12-21 00:24:41.362021 | 
2025-12-21 00:24:41.362140 | TASK [bindep : Include install tasks]
2025-12-21 00:24:41.386641 | controller | skipping: Conditional result was False
2025-12-21 00:24:41.395952 | 
2025-12-21 00:24:41.396072 | LOOP [bindep : Include package tasks]
2025-12-21 00:24:41.464890 | 
2025-12-21 00:24:41.465163 | TASK [Run test-setup role]
2025-12-21 00:24:41.490628 | controller | ok
2025-12-21 00:24:41.513673 | 
2025-12-21 00:24:41.513839 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-21 00:24:41.734382 | controller | ok
2025-12-21 00:24:41.747758 | 
2025-12-21 00:24:41.747929 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-21 00:24:42.301518 | controller | skipping: Conditional result was False
2025-12-21 00:24:42.349313 | 
2025-12-21 00:24:42.349617 | PLAY RECAP
2025-12-21 00:24:42.349705 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-21 00:24:42.349740 | 
2025-12-21 00:24:42.471353 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-21 00:24:42.473079 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-21 00:24:43.084751 | 
2025-12-21 00:24:43.084921 | PLAY [controller]
2025-12-21 00:24:43.106227 | 
2025-12-21 00:24:43.106325 | TASK [Create the /root directory]
2025-12-21 00:24:43.542572 | controller | ok
2025-12-21 00:24:43.556773 | 
2025-12-21 00:24:43.557030 | TASK [Install glibc-langpack-en]
2025-12-21 00:24:47.384787 | controller | ok: Nothing to do
2025-12-21 00:24:47.398663 | 
2025-12-21 00:24:47.398877 | TASK [Ensure controller directory exists]
2025-12-21 00:24:47.634500 | controller | changed
2025-12-21 00:24:47.649291 | 
2025-12-21 00:24:47.649442 | TASK [Install container runtime]
2025-12-21 00:24:47.736067 | controller | ok
2025-12-21 00:24:47.801270 | 
2025-12-21 00:24:47.801429 | LOOP [ensure-podman : Find distribution installation]
2025-12-21 00:24:47.857880 | controller | ok: "/var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-21 00:24:47.879935 | controller | included: /var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-21 00:24:47.897508 | 
2025-12-21 00:24:47.897673 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-21 00:25:51.917704 | controller | changed
2025-12-21 00:25:51.933659 | 
2025-12-21 00:25:51.933845 | TASK [ensure-podman : Fetch podman version]
2025-12-21 00:25:52.509311 | controller | Client:       Podman Engine
2025-12-21 00:25:52.542806 | controller | Version:      4.6.2
2025-12-21 00:25:52.542923 | controller | API Version:  4.6.2
2025-12-21 00:25:52.542939 | controller | Go Version:   go1.19.12
2025-12-21 00:25:52.542979 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-21 00:25:52.542996 | controller | OS/Arch:      linux/amd64
2025-12-21 00:25:52.990289 | controller | ok: Runtime: 0:00:00.199647
2025-12-21 00:25:53.007084 | 
2025-12-21 00:25:53.007241 | TASK [ensure-podman : Print podman version installed]
2025-12-21 00:25:53.042503 | Podman version: Client:       Podman Engine
2025-12-21 00:25:53.042734 | Version:      4.6.2
2025-12-21 00:25:53.042773 | API Version:  4.6.2
2025-12-21 00:25:53.042800 | Go Version:   go1.19.12
2025-12-21 00:25:53.042825 | Built:        Mon Aug 28 19:38:31 2023
2025-12-21 00:25:53.042852 | OS/Arch:      linux/amd64
2025-12-21 00:25:53.051095 | 
2025-12-21 00:25:53.051173 | TASK [ensure-podman : Validate podman engine]
2025-12-21 00:25:53.593049 | controller | skipping: Conditional result was False
2025-12-21 00:25:53.608496 | 
2025-12-21 00:25:53.608663 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-21 00:25:53.636341 | controller | skipping: Conditional result was False
2025-12-21 00:25:53.663021 | 
2025-12-21 00:25:53.663183 | TASK [Ensure python3.8 is present]
2025-12-21 00:25:53.690585 | controller | skipping: Conditional result was False
2025-12-21 00:25:53.699009 | 
2025-12-21 00:25:53.699097 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-21 00:25:53.721409 | controller | ok
2025-12-21 00:25:53.747946 | 
2025-12-21 00:25:53.748049 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-21 00:25:55.268266 | controller | ok: Nothing to do
2025-12-21 00:25:55.282057 | 
2025-12-21 00:25:55.282212 | TASK [our-ensure-python : Also install python3-devel]
2025-12-21 00:26:04.186861 | controller | changed
2025-12-21 00:26:04.210829 | 
2025-12-21 00:26:04.210979 | TASK [Run ensure-virtualenv role]
2025-12-21 00:26:04.239986 | controller | ok
2025-12-21 00:26:04.276769 | 
2025-12-21 00:26:04.276927 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-21 00:26:04.493255 | controller | /usr/bin/virtualenv
2025-12-21 00:26:04.813408 | controller | ok: Runtime: 0:00:00.004333
2025-12-21 00:26:04.834369 | 
2025-12-21 00:26:04.834514 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-21 00:26:04.872561 | controller | skipping: Conditional result was False
2025-12-21 00:26:04.873184 | controller | ok: All items complete
2025-12-21 00:26:04.873267 | 
2025-12-21 00:26:04.901086 | 
2025-12-21 00:26:04.901329 | TASK [Find the full path of the Python interpreter]
2025-12-21 00:26:05.177064 | controller | /usr/bin/python3
2025-12-21 00:26:05.482476 | controller | ok
2025-12-21 00:26:05.497375 | 
2025-12-21 00:26:05.497533 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-21 00:26:06.303943 | controller | created virtual environment CPython3.11.0.final.0-64 in 460ms
2025-12-21 00:26:06.331228 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-21 00:26:06.331628 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2025-12-21 00:26:06.331756 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-21 00:26:06.331771 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-21 00:26:06.554998 | controller | changed
2025-12-21 00:26:06.563979 | 
2025-12-21 00:26:06.564073 | TASK [Set selinux package]
2025-12-21 00:26:06.598615 | controller | ok
2025-12-21 00:26:06.606271 | 
2025-12-21 00:26:06.606366 | TASK [Set selinux package (Fedora)]
2025-12-21 00:26:06.661035 | controller | ok
2025-12-21 00:26:06.667977 | 
2025-12-21 00:26:06.668064 | TASK [Install selinux into virtualenv]
2025-12-21 00:26:44.105239 | controller | Collecting selinux-please-lie-to-me
2025-12-21 00:26:56.363423 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-21 00:26:56.682406 | controller | Collecting setuptools<50.0.0
2025-12-21 00:26:56.688005 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-21 00:26:56.724832 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.5 MB/s eta 0:00:00
2025-12-21 00:26:56.806873 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-21 00:26:56.807101 | controller |   Attempting uninstall: setuptools
2025-12-21 00:26:56.809628 | controller |     Found existing installation: setuptools 62.6.0
2025-12-21 00:26:56.868620 | controller |     Uninstalling setuptools-62.6.0:
2025-12-21 00:26:56.877355 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-21 00:26:57.226111 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-21 00:27:12.611067 | controller |
2025-12-21 00:27:12.700234 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-21 00:27:12.700286 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-21 00:27:12.750468 | controller | ok: Runtime: 0:01:05.812175
2025-12-21 00:27:12.757117 | 
2025-12-21 00:27:12.757212 | TASK [Install pytest-forked into virtualenv]
2025-12-21 00:27:25.682690 | controller | Collecting pytest-forked
2025-12-21 00:27:37.902744 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-21 00:27:37.967721 | controller | Collecting py
2025-12-21 00:27:37.973034 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-21 00:27:37.994243 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.5 MB/s eta 0:00:00
2025-12-21 00:27:38.106268 | controller | Collecting pytest>=3.10
2025-12-21 00:27:38.113919 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-21 00:27:38.130694 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 26.8 MB/s eta 0:00:00
2025-12-21 00:27:38.172608 | controller | Collecting iniconfig>=1.0.1
2025-12-21 00:27:38.176194 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-21 00:27:38.231880 | controller | Collecting packaging>=22
2025-12-21 00:27:38.235722 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-21 00:27:38.240607 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 19.1 MB/s eta 0:00:00
2025-12-21 00:27:38.273193 | controller | Collecting pluggy<2,>=1.5
2025-12-21 00:27:38.277822 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-21 00:27:38.325617 | controller | Collecting pygments>=2.7.2
2025-12-21 00:27:38.328896 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-21 00:27:38.349223 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 70.1 MB/s eta 0:00:00
2025-12-21 00:27:38.420045 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-21 00:27:39.467715 | 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
2025-12-21 00:27:39.476405 | controller |
2025-12-21 00:27:39.542868 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-21 00:27:39.542931 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-21 00:27:39.803237 | controller | ok: Runtime: 0:00:26.578494
2025-12-21 00:27:39.819304 | 
2025-12-21 00:27:39.819444 | TASK [Update pip]
2025-12-21 00:27:40.355832 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-21 00:28:02.223522 | controller | Collecting pip
2025-12-21 00:28:14.574625 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-21 00:28:14.632874 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 34.0 MB/s eta 0:00:00
2025-12-21 00:28:14.698093 | controller | Installing collected packages: pip
2025-12-21 00:28:14.698212 | controller |   Attempting uninstall: pip
2025-12-21 00:28:14.700543 | controller |     Found existing installation: pip 22.2.2
2025-12-21 00:28:14.839699 | controller |     Uninstalling pip-22.2.2:
2025-12-21 00:28:14.855347 | controller |       Successfully uninstalled pip-22.2.2
2025-12-21 00:28:15.646017 | controller | Successfully installed pip-25.3
2025-12-21 00:28:16.570117 | controller | ok: Runtime: 0:00:35.686978
2025-12-21 00:28:16.582260 | 
2025-12-21 00:28:16.582392 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-21 00:28:16.807292 | controller | changed
2025-12-21 00:28:16.833474 | 
2025-12-21 00:28:16.833743 | TASK [Install ansible into virtualenv]
2025-12-21 00:28:17.351979 | controller | Processing ./src/github.com/ansible/ansible
2025-12-21 00:28:17.355139 | controller |   Installing build dependencies: started
2025-12-21 00:29:06.726206 | controller |   Installing build dependencies: finished with status 'done'
2025-12-21 00:29:06.727465 | controller |   Getting requirements to build wheel: started
2025-12-21 00:29:07.467578 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-21 00:29:07.469425 | controller |   Preparing metadata (pyproject.toml): started
2025-12-21 00:29:07.935287 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-21 00:29:07.941073 | 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.
2025-12-21 00:29:07.944669 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-21 00:29:08.412884 | controller | ERROR
2025-12-21 00:29:08.413234 | controller | {
2025-12-21 00:29:08.413274 | controller |   "delta": "0:00:50.947276",
2025-12-21 00:29:08.413302 | controller |   "end": "2025-12-21 00:29:08.012058",
2025-12-21 00:29:08.413327 | controller |   "msg": "non-zero return code",
2025-12-21 00:29:08.413365 | controller |   "rc": 1,
2025-12-21 00:29:08.413391 | controller |   "start": "2025-12-21 00:28:17.064782"
2025-12-21 00:29:08.413416 | controller | }
failure
2025-12-21 00:29:08.415735 | 
2025-12-21 00:29:08.415799 | PLAY RECAP
2025-12-21 00:29:08.415858 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-21 00:29:08.415907 | 
2025-12-21 00:29:08.540516 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-21 00:29:08.541460 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-21 00:29:09.150260 | 
2025-12-21 00:29:09.150397 | PLAY [all]
2025-12-21 00:29:09.172728 | 
2025-12-21 00:29:09.172859 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-21 00:29:09.438076 | controller | changed: non-zero return code
2025-12-21 00:29:09.444167 | 
2025-12-21 00:29:09.444242 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-21 00:29:09.469275 | controller | skipping: Conditional result was False
2025-12-21 00:29:09.475958 | 
2025-12-21 00:29:09.476026 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-21 00:29:09.521168 | 
2025-12-21 00:29:09.521386 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-21 00:29:09.567252 | 
2025-12-21 00:29:09.567434 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-21 00:29:09.593502 | controller | skipping: Conditional result was False
2025-12-21 00:29:09.604169 | 
2025-12-21 00:29:09.604270 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-21 00:29:09.638804 | 
2025-12-21 00:29:09.638999 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-21 00:29:09.675037 | controller | skipping: Conditional result was False
2025-12-21 00:29:09.684352 | 
2025-12-21 00:29:09.684469 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-21 00:29:09.711375 | controller | skipping: Conditional result was False
2025-12-21 00:29:09.721251 | 
2025-12-21 00:29:09.721350 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-21 00:29:09.747793 | controller | skipping: Conditional result was False
2025-12-21 00:29:09.784225 | 
2025-12-21 00:29:09.784296 | PLAY RECAP
2025-12-21 00:29:09.784340 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-21 00:29:09.784361 | 
2025-12-21 00:29:09.904946 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-21 00:29:09.905902 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-21 00:29:10.642744 | 
2025-12-21 00:29:10.642902 | PLAY [all:!appliance*]
2025-12-21 00:29:10.678342 | 
2025-12-21 00:29:10.678433 | TASK [unregister the node]
2025-12-21 00:29:11.217844 | controller | skipping: Conditional result was False
2025-12-21 00:29:11.224237 | 
2025-12-21 00:29:11.224319 | TASK [include_role : fetch-output]
2025-12-21 00:29:11.255243 | controller | ok
2025-12-21 00:29:11.276561 | 
2025-12-21 00:29:11.276726 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-21 00:29:11.321721 | controller | skipping: Conditional result was False
2025-12-21 00:29:11.328183 | 
2025-12-21 00:29:11.328268 | TASK [fetch-output : Set log path for single node]
2025-12-21 00:29:11.358386 | controller | ok
2025-12-21 00:29:11.363715 | 
2025-12-21 00:29:11.363780 | LOOP [fetch-output : Ensure local output dirs]
2025-12-21 00:29:11.748595 | controller -> localhost | ok: "/var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/logs"
2025-12-21 00:29:11.984932 | controller -> localhost | changed: "/var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/artifacts"
2025-12-21 00:29:12.236772 | controller -> localhost | changed: "/var/lib/zuul/builds/1d99e3d8dad64b5d8d9d19a879d40c9b/work/docs"
2025-12-21 00:29:12.260405 | 
2025-12-21 00:29:12.260612 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-21 00:29:12.890415 | controller | changed:
2025-12-21 00:29:12.890653 | controller | .d..t...... ./
2025-12-21 00:29:12.890680 | controller | cd+++++++++ controller/
2025-12-21 00:29:12.890734 | controller | changed: All items complete
2025-12-21 00:29:12.890755 | 
2025-12-21 00:29:13.418888 | controller | changed: .d..t...... ./
2025-12-21 00:29:13.981972 | controller | changed: .d..t...... ./
2025-12-21 00:29:14.017896 | 
2025-12-21 00:29:14.018049 | TASK [include_role : fetch-output-openshift]
2025-12-21 00:29:14.044117 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.055321 | 
2025-12-21 00:29:14.055486 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-21 00:29:14.091924 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.102775 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.150502 | 
2025-12-21 00:29:14.150590 | PLAY [localhost]
2025-12-21 00:29:14.163414 | 
2025-12-21 00:29:14.163481 | TASK [Run Zuul manifest role]
2025-12-21 00:29:14.182546 | localhost | ok
2025-12-21 00:29:14.196624 | 
2025-12-21 00:29:14.196709 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-21 00:29:14.576617 | localhost | changed
2025-12-21 00:29:14.587139 | 
2025-12-21 00:29:14.587281 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-21 00:29:14.628082 | localhost | ok
2025-12-21 00:29:14.648528 | 
2025-12-21 00:29:14.648631 | TASK [Set zuul-log-path fact]
2025-12-21 00:29:14.671033 | localhost | ok
2025-12-21 00:29:14.690535 | 
2025-12-21 00:29:14.690629 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-21 00:29:14.734754 | localhost | ok
2025-12-21 00:29:14.746376 | 
2025-12-21 00:29:14.746469 | LOOP [Run upload-logs-swift role]
2025-12-21 00:29:14.795231 | localhost | Output suppressed because no_log was given
2025-12-21 00:29:14.833466 | 
2025-12-21 00:29:14.833612 | TASK [Set zuul-log-path fact]
2025-12-21 00:29:14.871560 | localhost | skipping: Conditional result was False
2025-12-21 00:29:14.884805 | 
2025-12-21 00:29:14.884960 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-21 00:29:15.339364 | localhost -> localhost | ok: Runtime: 0:00:00.009697
2025-12-21 00:29:15.346268 | 
2025-12-21 00:29:15.346333 | TASK [upload-logs-swift : Upload logs to swift]