2025-12-01 00:29:30.893235 | Job console starting...
2025-12-01 00:29:30.903058 | Updating repositories
2025-12-01 00:29:30.999139 | Preparing job workspace
2025-12-01 00:29:36.128917 | Running Ansible setup...
2025-12-01 00:29:43.863262 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-01 00:29:44.494324 | 
2025-12-01 00:29:44.494443 | PLAY [localhost]
2025-12-01 00:29:44.502932 | 
2025-12-01 00:29:44.503004 | TASK [Gathering Facts]
2025-12-01 00:29:45.551448 | localhost | ok
2025-12-01 00:29:45.568613 | 
2025-12-01 00:29:45.568772 | TASK [Setup log path fact]
2025-12-01 00:29:45.594022 | localhost | ok
2025-12-01 00:29:45.618994 | 
2025-12-01 00:29:45.619130 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 00:29:45.651185 | localhost | ok
2025-12-01 00:29:45.662503 | 
2025-12-01 00:29:45.662596 | TASK [emit-job-header : Print job information]
2025-12-01 00:29:45.703003 | # Job Information
2025-12-01 00:29:45.703154 | Ansible Version: 2.15.12
2025-12-01 00:29:45.703195 | Job: ansible-test-sanity-docker-devel
2025-12-01 00:29:45.703223 | Pipeline: periodic
2025-12-01 00:29:45.703247 | Executor: ze03.softwarefactory-project.io
2025-12-01 00:29:45.703271 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-01 00:29:45.703300 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/924/ansible/924524e9ac104ee79b228556051f72a3/
2025-12-01 00:29:45.703326 | Event ID: 7f239586727e4cf3b26e006c8a5b9dc9
2025-12-01 00:29:45.708401 | 
2025-12-01 00:29:45.708485 | LOOP [emit-job-header : Print node information]
2025-12-01 00:29:45.826260 | localhost | ok:
2025-12-01 00:29:45.826526 | localhost | # Node Information
2025-12-01 00:29:45.826583 | localhost | Inventory Hostname: controller
2025-12-01 00:29:45.826624 | localhost | Hostname: np0005540488
2025-12-01 00:29:45.826665 | localhost | Username: zuul
2025-12-01 00:29:45.826712 | localhost | Distro: Fedora 37
2025-12-01 00:29:45.826808 | localhost | Provider: ansible-vexxhost-ams1
2025-12-01 00:29:45.826849 | localhost | Region: ams1
2025-12-01 00:29:45.826885 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-01 00:29:45.826921 | localhost | Product Name: OpenStack Nova
2025-12-01 00:29:45.826957 | localhost | Interface IP: 38.129.16.107
2025-12-01 00:29:45.844182 | 
2025-12-01 00:29:45.844328 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-01 00:29:46.292049 | localhost -> localhost | changed
2025-12-01 00:29:46.297631 | 
2025-12-01 00:29:46.297700 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-01 00:29:47.235294 | localhost -> localhost | changed
2025-12-01 00:29:47.254269 | 
2025-12-01 00:29:47.254344 | PLAY [all:!appliance*]
2025-12-01 00:29:47.270142 | 
2025-12-01 00:29:47.270240 | TASK [include_role : start-zuul-console]
2025-12-01 00:29:47.289072 | controller | ok
2025-12-01 00:29:47.302327 | 
2025-12-01 00:29:47.302411 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-01 00:29:48.247571 | controller | ok
2025-12-01 00:29:48.272601 | 
2025-12-01 00:29:48.272835 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-01 00:29:50.876544 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-01 00:29:50.892407 | 
2025-12-01 00:29:50.892587 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-01 00:29:51.265436 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.276268 | 
2025-12-01 00:29:51.276379 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-01 00:29:51.301279 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.319151 | 
2025-12-01 00:29:51.319338 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-01 00:29:51.346870 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.363586 | 
2025-12-01 00:29:51.363824 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-01 00:29:51.391447 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.400604 | 
2025-12-01 00:29:51.400773 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-01 00:29:51.435363 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.444171 | 
2025-12-01 00:29:51.444295 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-01 00:29:51.468798 | controller | skipping: Conditional result was False
2025-12-01 00:29:51.484492 | 
2025-12-01 00:29:51.484628 | TASK [Disable Fedora Modular]
2025-12-01 00:29:52.372210 | controller | changed
2025-12-01 00:29:52.386401 | 
2025-12-01 00:29:52.386678 | TASK [Enable EPEL]
2025-12-01 00:29:52.424097 | controller | skipping: Conditional result was False
2025-12-01 00:29:52.439709 | 
2025-12-01 00:29:52.439961 | TASK [Register the RHEL node]
2025-12-01 00:29:52.851837 | 
2025-12-01 00:29:52.852030 | TASK [Show the subscription-manager status]
2025-12-01 00:29:53.219812 | controller | skipping: Conditional result was False
2025-12-01 00:29:53.239307 | 
2025-12-01 00:29:53.239478 | TASK [Enable EPEL on RHEL]
2025-12-01 00:29:53.619472 | controller | skipping: Conditional result was False
2025-12-01 00:29:53.634674 | 
2025-12-01 00:29:53.635167 | TASK [Install git and tox]
2025-12-01 00:32:21.807377 | controller | changed
2025-12-01 00:32:21.825516 | 
2025-12-01 00:32:21.825706 | TASK [include_role : prepare-workspace]
2025-12-01 00:32:21.865995 | controller | ok
2025-12-01 00:32:21.903424 | 
2025-12-01 00:32:21.903556 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-01 00:32:22.744708 | controller | ok
2025-12-01 00:32:22.752929 | 
2025-12-01 00:32:22.753011 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-01 00:32:38.227895 | controller | Output suppressed because no_log was given
2025-12-01 00:32:38.237862 | 
2025-12-01 00:32:38.237935 | TASK [include_role : prepare-workspace-openshift]
2025-12-01 00:32:38.257958 | controller | skipping: Conditional result was False
2025-12-01 00:32:38.329777 | 
2025-12-01 00:32:38.329856 | PLAY [all:!appliance]
2025-12-01 00:32:38.345489 | 
2025-12-01 00:32:38.345579 | TASK [Run add-build-sshkey role (RSA)]
2025-12-01 00:32:38.364962 | controller | ok
2025-12-01 00:32:38.381643 | 
2025-12-01 00:32:38.381779 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-01 00:32:38.640504 | controller -> localhost | ok
2025-12-01 00:32:38.648021 | 
2025-12-01 00:32:38.648140 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-01 00:32:38.688028 | controller | ok
2025-12-01 00:32:38.702486 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-01 00:32:38.710299 | 
2025-12-01 00:32:38.710395 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-01 00:32:39.196664 | controller -> localhost | Generating public/private rsa key pair.
2025-12-01 00:32:39.197113 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_rsa.
2025-12-01 00:32:39.197177 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_rsa.pub.
2025-12-01 00:32:39.197223 | controller -> localhost | The key fingerprint is:
2025-12-01 00:32:39.197267 | controller -> localhost | SHA256:fLm6v1Py7jmYxePb0DLkcFmdlL9Bnhy5kszmq/98Rm4 zuul-build-sshkey
2025-12-01 00:32:39.197308 | controller -> localhost | The key's randomart image is:
2025-12-01 00:32:39.197349 | controller -> localhost | +---[RSA 2048]----+
2025-12-01 00:32:39.197391 | controller -> localhost | |               .o|
2025-12-01 00:32:39.197433 | controller -> localhost | |              .*.|
2025-12-01 00:32:39.197473 | controller -> localhost | |            o *.*|
2025-12-01 00:32:39.197512 | controller -> localhost | |       .   . O *.|
2025-12-01 00:32:39.197551 | controller -> localhost | |        S +.* . o|
2025-12-01 00:32:39.197606 | controller -> localhost | |         ..*=o ..|
2025-12-01 00:32:39.197654 | controller -> localhost | |          .O=.oo |
2025-12-01 00:32:39.197694 | controller -> localhost | |         .+ +B. E|
2025-12-01 00:32:39.197776 | controller -> localhost | |        ooo*B+o=.|
2025-12-01 00:32:39.197825 | controller -> localhost | +----[SHA256]-----+
2025-12-01 00:32:39.197916 | controller -> localhost | ok: Runtime: 0:00:00.052638
2025-12-01 00:32:39.213199 | 
2025-12-01 00:32:39.213380 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-01 00:32:39.254451 | controller | ok
2025-12-01 00:32:39.280655 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-01 00:32:39.306485 | 
2025-12-01 00:32:39.306634 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-01 00:32:39.335128 | controller | skipping: Conditional result was False
2025-12-01 00:32:39.346284 | 
2025-12-01 00:32:39.346442 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-01 00:32:40.398994 | controller | changed
2025-12-01 00:32:40.416335 | 
2025-12-01 00:32:40.417515 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-01 00:32:41.052239 | controller | ok
2025-12-01 00:32:41.059584 | 
2025-12-01 00:32:41.059679 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-01 00:32:44.059330 | controller | changed
2025-12-01 00:32:44.070335 | 
2025-12-01 00:32:44.070572 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-01 00:32:47.031694 | controller | changed
2025-12-01 00:32:47.038001 | 
2025-12-01 00:32:47.038107 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-01 00:32:47.062427 | controller | skipping: Conditional result was False
2025-12-01 00:32:47.069340 | 
2025-12-01 00:32:47.069438 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-01 00:32:47.451390 | controller -> localhost | changed
2025-12-01 00:32:47.462388 | 
2025-12-01 00:32:47.462485 | TASK [add-build-sshkey : Add back temp key]
2025-12-01 00:32:47.723301 | controller -> localhost | Identity added: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_rsa (zuul-build-sshkey)
2025-12-01 00:32:47.723552 | controller -> localhost | ok: Runtime: 0:00:00.012936
2025-12-01 00:32:47.729906 | 
2025-12-01 00:32:47.729973 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-01 00:32:48.672928 | controller | ok
2025-12-01 00:32:48.680993 | 
2025-12-01 00:32:48.681095 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-01 00:32:48.706249 | controller | skipping: Conditional result was False
2025-12-01 00:32:48.723202 | 
2025-12-01 00:32:48.723317 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-01 00:32:48.755833 | controller | ok
2025-12-01 00:32:48.779851 | 
2025-12-01 00:32:48.779973 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-01 00:32:49.083879 | controller -> localhost | ok
2025-12-01 00:32:49.090458 | 
2025-12-01 00:32:49.090529 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-01 00:32:49.128447 | controller | ok
2025-12-01 00:32:49.145270 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-01 00:32:49.154619 | 
2025-12-01 00:32:49.154732 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-01 00:32:49.447293 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-01 00:32:49.447668 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_ecdsa.
2025-12-01 00:32:49.447764 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_ecdsa.pub.
2025-12-01 00:32:49.447868 | controller -> localhost | The key fingerprint is:
2025-12-01 00:32:49.447942 | controller -> localhost | SHA256:pQDlfybFrxSmYCsw0I2InseKfL7MqxQxh62ncFMBYYQ zuul-build-sshkey
2025-12-01 00:32:49.448016 | controller -> localhost | The key's randomart image is:
2025-12-01 00:32:49.448083 | controller -> localhost | +---[ECDSA 521]---+
2025-12-01 00:32:49.448137 | controller -> localhost | |o===o..          |
2025-12-01 00:32:49.448177 | controller -> localhost | |Eo= .+   .       |
2025-12-01 00:32:49.448215 | controller -> localhost | |.+=o. =   *      |
2025-12-01 00:32:49.448253 | controller -> localhost | | o=* . = * o     |
2025-12-01 00:32:49.448290 | controller -> localhost | |+o=.. . S + .    |
2025-12-01 00:32:49.448326 | controller -> localhost | |o++o .   = .     |
2025-12-01 00:32:49.448363 | controller -> localhost | | oo       .      |
2025-12-01 00:32:49.448401 | controller -> localhost | |. o.             |
2025-12-01 00:32:49.448436 | controller -> localhost | | ..=o            |
2025-12-01 00:32:49.448473 | controller -> localhost | +----[SHA256]-----+
2025-12-01 00:32:49.448561 | controller -> localhost | ok: Runtime: 0:00:00.007607
2025-12-01 00:32:49.464224 | 
2025-12-01 00:32:49.464426 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-01 00:32:49.487448 | controller | ok
2025-12-01 00:32:49.497852 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-01 00:32:49.508067 | 
2025-12-01 00:32:49.508166 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-01 00:32:49.532850 | controller | skipping: Conditional result was False
2025-12-01 00:32:49.540630 | 
2025-12-01 00:32:49.540762 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-01 00:32:50.434560 | controller | changed
2025-12-01 00:32:50.443511 | 
2025-12-01 00:32:50.443619 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-01 00:32:51.128426 | controller | ok
2025-12-01 00:32:51.136764 | 
2025-12-01 00:32:51.136873 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-01 00:32:54.126953 | controller | changed
2025-12-01 00:32:54.136539 | 
2025-12-01 00:32:54.136688 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-01 00:32:57.125694 | controller | changed
2025-12-01 00:32:57.139199 | 
2025-12-01 00:32:57.139312 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-01 00:32:57.175119 | controller | skipping: Conditional result was False
2025-12-01 00:32:57.183933 | 
2025-12-01 00:32:57.184051 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-01 00:32:57.448229 | controller -> localhost | changed
2025-12-01 00:32:57.460710 | 
2025-12-01 00:32:57.460825 | TASK [add-build-sshkey : Add back temp key]
2025-12-01 00:32:57.749609 | controller -> localhost | Identity added: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/924524e9ac104ee79b228556051f72a3_id_ecdsa (zuul-build-sshkey)
2025-12-01 00:32:57.749868 | controller -> localhost | ok: Runtime: 0:00:00.011808
2025-12-01 00:32:57.757717 | 
2025-12-01 00:32:57.757827 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-01 00:32:58.450883 | controller | ok
2025-12-01 00:32:58.463010 | 
2025-12-01 00:32:58.463156 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-01 00:32:58.490647 | controller | skipping: Conditional result was False
2025-12-01 00:32:58.518933 | 
2025-12-01 00:32:58.519106 | TASK [include_role : remove-zuul-sshkey]
2025-12-01 00:32:58.546019 | controller | skipping: Conditional result was False
2025-12-01 00:32:58.560687 | 
2025-12-01 00:32:58.560904 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-01 00:32:59.185288 | controller | ok: "logs"
2025-12-01 00:32:59.185527 | controller | ok: All items complete
2025-12-01 00:32:59.185562 | 
2025-12-01 00:32:59.783181 | controller | ok: "artifacts"
2025-12-01 00:33:00.396554 | controller | ok: "docs"
2025-12-01 00:33:00.412030 | 
2025-12-01 00:33:00.412239 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-01 00:33:01.058251 | controller | changed: "logs"
2025-12-01 00:33:01.688425 | controller | changed: "artifacts"
2025-12-01 00:33:02.303660 | controller | changed: "docs"
2025-12-01 00:33:02.369228 | 
2025-12-01 00:33:02.369362 | PLAY RECAP
2025-12-01 00:33:02.369424 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-01 00:33:02.369463 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-01 00:33:02.369491 | 
2025-12-01 00:33:02.517926 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-01 00:33:02.518778 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 00:33:03.202026 | 
2025-12-01 00:33:03.202201 | PLAY [all]
2025-12-01 00:33:03.237858 | 
2025-12-01 00:33:03.238045 | TASK [Install binary dependencies]
2025-12-01 00:33:03.326098 | controller | ok
2025-12-01 00:33:03.347141 | 
2025-12-01 00:33:03.347283 | TASK [bindep : Include find tasks]
2025-12-01 00:33:03.391238 | controller | ok
2025-12-01 00:33:03.403402 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-01 00:33:03.413869 | 
2025-12-01 00:33:03.414049 | TASK [bindep : Look for bindep.txt]
2025-12-01 00:33:04.379343 | controller | ok
2025-12-01 00:33:04.387165 | 
2025-12-01 00:33:04.387257 | TASK [bindep : Define bindep_file fact]
2025-12-01 00:33:04.412289 | controller | skipping: Conditional result was False
2025-12-01 00:33:04.421230 | 
2025-12-01 00:33:04.421336 | TASK [bindep : Look for other-requirements.txt]
2025-12-01 00:33:05.058317 | controller | ok
2025-12-01 00:33:05.067060 | 
2025-12-01 00:33:05.067324 | TASK [bindep : Define bindep_file fact]
2025-12-01 00:33:05.103180 | controller | skipping: Conditional result was False
2025-12-01 00:33:05.117801 | 
2025-12-01 00:33:05.118262 | TASK [bindep : Look for bindep fallback file]
2025-12-01 00:33:05.157038 | controller | skipping: Conditional result was False
2025-12-01 00:33:05.167848 | 
2025-12-01 00:33:05.167989 | TASK [bindep : Define bindep_file fact]
2025-12-01 00:33:05.204352 | controller | skipping: Conditional result was False
2025-12-01 00:33:05.211614 | 
2025-12-01 00:33:05.211749 | TASK [bindep : Include bindep tasks]
2025-12-01 00:33:05.236498 | controller | skipping: Conditional result was False
2025-12-01 00:33:05.245934 | 
2025-12-01 00:33:05.246052 | TASK [bindep : Include install tasks]
2025-12-01 00:33:05.271412 | controller | skipping: Conditional result was False
2025-12-01 00:33:05.280281 | 
2025-12-01 00:33:05.280380 | LOOP [bindep : Include package tasks]
2025-12-01 00:33:05.368064 | 
2025-12-01 00:33:05.368398 | TASK [Run test-setup role]
2025-12-01 00:33:05.399600 | controller | ok
2025-12-01 00:33:05.430461 | 
2025-12-01 00:33:05.430599 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-01 00:33:06.143501 | controller | ok
2025-12-01 00:33:06.158997 | 
2025-12-01 00:33:06.159157 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-01 00:33:06.524900 | controller | skipping: Conditional result was False
2025-12-01 00:33:06.563270 | 
2025-12-01 00:33:06.563375 | PLAY RECAP
2025-12-01 00:33:06.563430 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-01 00:33:06.563460 | 
2025-12-01 00:33:06.683077 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 00:33:06.684238 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-01 00:33:07.352134 | 
2025-12-01 00:33:07.352269 | PLAY [controller]
2025-12-01 00:33:07.371660 | 
2025-12-01 00:33:07.371764 | TASK [Create the /root directory]
2025-12-01 00:33:08.428549 | controller | ok
2025-12-01 00:33:08.441063 | 
2025-12-01 00:33:08.441216 | TASK [Install glibc-langpack-en]
2025-12-01 00:33:15.949647 | controller | ok: Nothing to do
2025-12-01 00:33:15.957225 | 
2025-12-01 00:33:15.957304 | TASK [Ensure controller directory exists]
2025-12-01 00:33:16.759556 | controller | changed
2025-12-01 00:33:16.770185 | 
2025-12-01 00:33:16.770321 | TASK [Install container runtime]
2025-12-01 00:33:16.827653 | controller | ok
2025-12-01 00:33:16.876300 | 
2025-12-01 00:33:16.876419 | LOOP [ensure-podman : Find distribution installation]
2025-12-01 00:33:16.903496 | controller | ok: "/var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-01 00:33:16.919261 | controller | included: /var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-01 00:33:16.925734 | 
2025-12-01 00:33:16.925828 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-01 00:35:01.167282 | controller | changed
2025-12-01 00:35:01.184146 | 
2025-12-01 00:35:01.184332 | TASK [ensure-podman : Fetch podman version]
2025-12-01 00:35:02.270484 | controller | Client:       Podman Engine
2025-12-01 00:35:02.302400 | controller | Version:      4.6.2
2025-12-01 00:35:02.302452 | controller | API Version:  4.6.2
2025-12-01 00:35:02.302460 | controller | Go Version:   go1.19.12
2025-12-01 00:35:02.302478 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-01 00:35:02.302486 | controller | OS/Arch:      linux/amd64
2025-12-01 00:35:02.559567 | controller | ok: Runtime: 0:00:00.244513
2025-12-01 00:35:02.574845 | 
2025-12-01 00:35:02.575036 | TASK [ensure-podman : Print podman version installed]
2025-12-01 00:35:02.615463 | Podman version: Client:       Podman Engine
2025-12-01 00:35:02.615720 | Version:      4.6.2
2025-12-01 00:35:02.615820 | API Version:  4.6.2
2025-12-01 00:35:02.615866 | Go Version:   go1.19.12
2025-12-01 00:35:02.615905 | Built:        Mon Aug 28 19:38:31 2023
2025-12-01 00:35:02.615945 | OS/Arch:      linux/amd64
2025-12-01 00:35:02.628346 | 
2025-12-01 00:35:02.628469 | TASK [ensure-podman : Validate podman engine]
2025-12-01 00:35:02.994013 | controller | skipping: Conditional result was False
2025-12-01 00:35:03.009847 | 
2025-12-01 00:35:03.010049 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-01 00:35:03.038942 | controller | skipping: Conditional result was False
2025-12-01 00:35:03.066653 | 
2025-12-01 00:35:03.066875 | TASK [Ensure python3.8 is present]
2025-12-01 00:35:03.094653 | controller | skipping: Conditional result was False
2025-12-01 00:35:03.103536 | 
2025-12-01 00:35:03.103664 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-01 00:35:03.132140 | controller | ok
2025-12-01 00:35:03.164185 | 
2025-12-01 00:35:03.164337 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-01 00:35:06.439480 | controller | ok: Nothing to do
2025-12-01 00:35:06.452524 | 
2025-12-01 00:35:06.452698 | TASK [our-ensure-python : Also install python3-devel]
2025-12-01 00:35:21.375465 | controller | changed
2025-12-01 00:35:21.390641 | 
2025-12-01 00:35:21.390771 | TASK [Run ensure-virtualenv role]
2025-12-01 00:35:21.413616 | controller | ok
2025-12-01 00:35:21.452270 | 
2025-12-01 00:35:21.452390 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-01 00:35:22.186691 | controller | /usr/bin/virtualenv
2025-12-01 00:35:22.331556 | controller | ok: Runtime: 0:00:00.006092
2025-12-01 00:35:22.339214 | 
2025-12-01 00:35:22.339306 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-01 00:35:22.364630 | controller | skipping: Conditional result was False
2025-12-01 00:35:22.365270 | controller | ok: All items complete
2025-12-01 00:35:22.365312 | 
2025-12-01 00:35:22.388396 | 
2025-12-01 00:35:22.388575 | TASK [Find the full path of the Python interpreter]
2025-12-01 00:35:22.954346 | controller | /usr/bin/python3
2025-12-01 00:35:23.244993 | controller | ok
2025-12-01 00:35:23.254200 | 
2025-12-01 00:35:23.254318 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-01 00:35:24.975394 | controller | created virtual environment CPython3.11.0.final.0-64 in 763ms
2025-12-01 00:35:25.040878 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-01 00:35:25.040993 | 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-01 00:35:25.041029 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-01 00:35:25.041062 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-01 00:35:25.617990 | controller | changed
2025-12-01 00:35:25.637996 | 
2025-12-01 00:35:25.638184 | TASK [Set selinux package]
2025-12-01 00:35:25.675310 | controller | ok
2025-12-01 00:35:25.683990 | 
2025-12-01 00:35:25.684074 | TASK [Set selinux package (Fedora)]
2025-12-01 00:35:25.744107 | controller | ok
2025-12-01 00:35:25.757506 | 
2025-12-01 00:35:25.757695 | TASK [Install selinux into virtualenv]
2025-12-01 00:35:28.270200 | controller | Collecting selinux-please-lie-to-me
2025-12-01 00:35:28.326984 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-01 00:35:28.759544 | controller | Collecting setuptools<50.0.0
2025-12-01 00:35:28.764995 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-01 00:35:28.815814 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 17.5 MB/s eta 0:00:00
2025-12-01 00:35:28.940621 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-01 00:35:28.940942 | controller |   Attempting uninstall: setuptools
2025-12-01 00:35:28.944647 | controller |     Found existing installation: setuptools 62.6.0
2025-12-01 00:35:29.031584 | controller |     Uninstalling setuptools-62.6.0:
2025-12-01 00:35:29.043765 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-01 00:35:29.665351 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-01 00:35:29.837361 | controller |
2025-12-01 00:35:30.087097 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-01 00:35:30.087160 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-01 00:35:30.632876 | controller | ok: Runtime: 0:00:03.584306
2025-12-01 00:35:30.646035 | 
2025-12-01 00:35:30.646247 | TASK [Install pytest-forked into virtualenv]
2025-12-01 00:35:32.623221 | controller | Collecting pytest-forked
2025-12-01 00:35:32.678268 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-01 00:35:32.733626 | controller | Collecting py
2025-12-01 00:35:32.738809 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-01 00:35:32.770741 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.3 MB/s eta 0:00:00
2025-12-01 00:35:32.916646 | controller | Collecting pytest>=3.10
2025-12-01 00:35:32.922041 | controller |   Downloading pytest-9.0.1-py3-none-any.whl (373 kB)
2025-12-01 00:35:32.941556 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 24.2 MB/s eta 0:00:00
2025-12-01 00:35:32.990110 | controller | Collecting iniconfig>=1.0.1
2025-12-01 00:35:32.995596 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-01 00:35:33.056342 | controller | Collecting packaging>=22
2025-12-01 00:35:33.061320 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-01 00:35:33.071226 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.2 MB/s eta 0:00:00
2025-12-01 00:35:33.109328 | controller | Collecting pluggy<2,>=1.5
2025-12-01 00:35:33.114348 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-01 00:35:33.182482 | controller | Collecting pygments>=2.7.2
2025-12-01 00:35:33.187824 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-01 00:35:33.214878 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 57.0 MB/s eta 0:00:00
2025-12-01 00:35:33.310935 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-01 00:35:35.307181 | 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.1 pytest-forked-1.6.0
2025-12-01 00:35:35.326673 | controller |
2025-12-01 00:35:35.613617 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-01 00:35:35.613681 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-01 00:35:36.040452 | controller | ok: Runtime: 0:00:03.658884
2025-12-01 00:35:36.054073 | 
2025-12-01 00:35:36.054252 | TASK [Update pip]
2025-12-01 00:35:37.369262 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-01 00:35:37.601719 | controller | Collecting pip
2025-12-01 00:35:37.652549 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-01 00:35:37.713132 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 31.4 MB/s eta 0:00:00
2025-12-01 00:35:37.812188 | controller | Installing collected packages: pip
2025-12-01 00:35:37.813921 | controller |   Attempting uninstall: pip
2025-12-01 00:35:37.819304 | controller |     Found existing installation: pip 22.2.2
2025-12-01 00:35:38.026735 | controller |     Uninstalling pip-22.2.2:
2025-12-01 00:35:38.049319 | controller |       Successfully uninstalled pip-22.2.2
2025-12-01 00:35:40.009402 | controller | Successfully installed pip-25.3
2025-12-01 00:35:40.945390 | controller | ok: Runtime: 0:00:03.431199
2025-12-01 00:35:40.954163 | 
2025-12-01 00:35:40.954363 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-01 00:35:41.867955 | controller | changed
2025-12-01 00:35:41.874518 | 
2025-12-01 00:35:41.874799 | TASK [Install ansible into virtualenv]
2025-12-01 00:35:43.531200 | controller | Processing ./src/github.com/ansible/ansible
2025-12-01 00:35:43.536503 | controller |   Installing build dependencies: started
2025-12-01 00:35:45.358399 | controller |   Installing build dependencies: finished with status 'done'
2025-12-01 00:35:46.798220 | controller |   Getting requirements to build wheel: started
2025-12-01 00:35:46.798329 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-01 00:35:47.645377 | controller |   Preparing metadata (pyproject.toml): started
2025-12-01 00:35:47.645452 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-01 00:35:47.648672 | 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-01 00:35:47.652743 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-01 00:35:48.258804 | controller | ERROR
2025-12-01 00:35:48.259094 | controller | {
2025-12-01 00:35:48.259156 | controller |   "delta": "0:00:05.167856",
2025-12-01 00:35:48.259201 | controller |   "end": "2025-12-01 00:35:47.851187",
2025-12-01 00:35:48.259241 | controller |   "msg": "non-zero return code",
2025-12-01 00:35:48.259293 | controller |   "rc": 1,
2025-12-01 00:35:48.259328 | controller |   "start": "2025-12-01 00:35:42.683331"
2025-12-01 00:35:48.259362 | controller | }
failure
2025-12-01 00:35:48.262027 | 
2025-12-01 00:35:48.262124 | PLAY RECAP
2025-12-01 00:35:48.262207 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-01 00:35:48.262250 | 
2025-12-01 00:35:48.385877 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-01 00:35:48.386888 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 00:35:48.994447 | 
2025-12-01 00:35:48.994606 | PLAY [all]
2025-12-01 00:35:49.017710 | 
2025-12-01 00:35:49.017861 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-01 00:35:50.841395 | controller | changed: non-zero return code
2025-12-01 00:35:50.851907 | 
2025-12-01 00:35:50.852072 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-01 00:35:50.880354 | controller | skipping: Conditional result was False
2025-12-01 00:35:50.889431 | 
2025-12-01 00:35:50.889576 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-01 00:35:50.936111 | 
2025-12-01 00:35:50.936281 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-01 00:35:50.957716 | 
2025-12-01 00:35:50.957991 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-01 00:35:50.976664 | controller | skipping: Conditional result was False
2025-12-01 00:35:50.984005 | 
2025-12-01 00:35:50.984137 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-01 00:35:51.009162 | 
2025-12-01 00:35:51.009397 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-01 00:35:51.039760 | controller | skipping: Conditional result was False
2025-12-01 00:35:51.046002 | 
2025-12-01 00:35:51.046119 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-01 00:35:51.060512 | controller | skipping: Conditional result was False
2025-12-01 00:35:51.067915 | 
2025-12-01 00:35:51.068039 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-01 00:35:51.084483 | controller | skipping: Conditional result was False
2025-12-01 00:35:51.116542 | 
2025-12-01 00:35:51.116717 | PLAY RECAP
2025-12-01 00:35:51.116801 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-01 00:35:51.116822 | 
2025-12-01 00:35:51.343324 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 00:35:51.344218 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-01 00:35:51.958081 | 
2025-12-01 00:35:51.958214 | PLAY [all:!appliance*]
2025-12-01 00:35:51.989998 | 
2025-12-01 00:35:51.990135 | TASK [unregister the node]
2025-12-01 00:35:52.344039 | controller | skipping: Conditional result was False
2025-12-01 00:35:52.358473 | 
2025-12-01 00:35:52.359372 | TASK [include_role : fetch-output]
2025-12-01 00:35:52.405516 | controller | ok
2025-12-01 00:35:52.435914 | 
2025-12-01 00:35:52.436067 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-01 00:35:52.502176 | controller | skipping: Conditional result was False
2025-12-01 00:35:52.509799 | 
2025-12-01 00:35:52.509894 | TASK [fetch-output : Set log path for single node]
2025-12-01 00:35:52.550257 | controller | ok
2025-12-01 00:35:52.556003 | 
2025-12-01 00:35:52.556106 | LOOP [fetch-output : Ensure local output dirs]
2025-12-01 00:35:52.958917 | controller -> localhost | ok: "/var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/logs"
2025-12-01 00:35:53.209827 | controller -> localhost | changed: "/var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/artifacts"
2025-12-01 00:35:53.440437 | controller -> localhost | changed: "/var/lib/zuul/builds/924524e9ac104ee79b228556051f72a3/work/docs"
2025-12-01 00:35:53.455662 | 
2025-12-01 00:35:53.455785 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-01 00:35:55.687221 | controller | changed:
2025-12-01 00:35:55.687567 | controller | .d..t...... ./
2025-12-01 00:35:55.687609 | controller | cd+++++++++ controller/
2025-12-01 00:35:55.687649 | controller | changed: All items complete
2025-12-01 00:35:55.687671 | 
2025-12-01 00:35:57.702450 | controller | changed: .d..t...... ./
2025-12-01 00:35:59.775925 | controller | changed: .d..t...... ./
2025-12-01 00:35:59.806065 | 
2025-12-01 00:35:59.806267 | TASK [include_role : fetch-output-openshift]
2025-12-01 00:35:59.824454 | controller | skipping: Conditional result was False
2025-12-01 00:35:59.837656 | 
2025-12-01 00:35:59.837869 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-01 00:35:59.867794 | controller | skipping: Conditional result was False
2025-12-01 00:35:59.876163 | controller | skipping: Conditional result was False
2025-12-01 00:35:59.924696 | 
2025-12-01 00:35:59.924839 | PLAY [localhost]
2025-12-01 00:35:59.943052 | 
2025-12-01 00:35:59.943188 | TASK [Run Zuul manifest role]
2025-12-01 00:35:59.965981 | localhost | ok
2025-12-01 00:35:59.984767 | 
2025-12-01 00:35:59.984906 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-01 00:36:00.362083 | localhost | changed
2025-12-01 00:36:00.367034 | 
2025-12-01 00:36:00.367137 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-01 00:36:00.396125 | localhost | ok
2025-12-01 00:36:00.405008 | 
2025-12-01 00:36:00.405126 | TASK [Set zuul-log-path fact]
2025-12-01 00:36:00.424135 | localhost | ok
2025-12-01 00:36:00.470826 | 
2025-12-01 00:36:00.470953 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 00:36:00.512374 | localhost | ok
2025-12-01 00:36:00.522131 | 
2025-12-01 00:36:00.522256 | LOOP [Run upload-logs-swift role]
2025-12-01 00:36:00.568156 | localhost | Output suppressed because no_log was given
2025-12-01 00:36:00.616359 | 
2025-12-01 00:36:00.616512 | TASK [Set zuul-log-path fact]
2025-12-01 00:36:00.641201 | localhost | skipping: Conditional result was False
2025-12-01 00:36:00.646918 | 
2025-12-01 00:36:00.646992 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-01 00:36:01.060288 | localhost -> localhost | ok: Runtime: 0:00:00.008715
2025-12-01 00:36:01.072569 | 
2025-12-01 00:36:01.072761 | TASK [upload-logs-swift : Upload logs to swift]