2025-12-03 00:06:40.371757 | Job console starting...
2025-12-03 00:06:40.383290 | Updating repositories
2025-12-03 00:06:43.587553 | Preparing job workspace
2025-12-03 00:06:49.965869 | Running Ansible setup...
2025-12-03 00:06:56.400246 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-03 00:06:57.045503 | 
2025-12-03 00:06:57.045640 | PLAY [localhost]
2025-12-03 00:06:57.054452 | 
2025-12-03 00:06:57.054522 | TASK [Gathering Facts]
2025-12-03 00:06:58.050959 | localhost | ok
2025-12-03 00:06:58.080392 | 
2025-12-03 00:06:58.080549 | TASK [Setup log path fact]
2025-12-03 00:06:58.114225 | localhost | ok
2025-12-03 00:06:58.126942 | 
2025-12-03 00:06:58.127026 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 00:06:58.154454 | localhost | ok
2025-12-03 00:06:58.162238 | 
2025-12-03 00:06:58.162327 | TASK [emit-job-header : Print job information]
2025-12-03 00:06:58.192973 | # Job Information
2025-12-03 00:06:58.193133 | Ansible Version: 2.15.12
2025-12-03 00:06:58.193163 | Job: ansible-test-sanity-docker-devel
2025-12-03 00:06:58.193183 | Pipeline: periodic
2025-12-03 00:06:58.193202 | Executor: ze02.softwarefactory-project.io
2025-12-03 00:06:58.193220 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-03 00:06:58.193240 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/62b/ansible/62b0e0be5e4341acbde1db009b4362ba/
2025-12-03 00:06:58.193259 | Event ID: 08d03c5eb6c54d3f91ad96751eb57522
2025-12-03 00:06:58.197208 | 
2025-12-03 00:06:58.197269 | LOOP [emit-job-header : Print node information]
2025-12-03 00:06:58.293232 | localhost | ok:
2025-12-03 00:06:58.293393 | localhost | # Node Information
2025-12-03 00:06:58.293420 | localhost | Inventory Hostname: controller
2025-12-03 00:06:58.293439 | localhost | Hostname: np0005543022
2025-12-03 00:06:58.293458 | localhost | Username: zuul
2025-12-03 00:06:58.293479 | localhost | Distro: Fedora 37
2025-12-03 00:06:58.293498 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-03 00:06:58.293515 | localhost | Region: ca-ymq-1
2025-12-03 00:06:58.293532 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-03 00:06:58.293548 | localhost | Product Name: OpenStack Nova
2025-12-03 00:06:58.293565 | localhost | Interface IP: 162.253.55.42
2025-12-03 00:06:58.310500 | 
2025-12-03 00:06:58.310627 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-03 00:06:58.756052 | localhost -> localhost | changed
2025-12-03 00:06:58.761879 | 
2025-12-03 00:06:58.761947 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-03 00:06:59.859330 | localhost -> localhost | changed
2025-12-03 00:06:59.878736 | 
2025-12-03 00:06:59.878809 | PLAY [all:!appliance*]
2025-12-03 00:06:59.895604 | 
2025-12-03 00:06:59.895685 | TASK [include_role : start-zuul-console]
2025-12-03 00:06:59.914452 | controller | ok
2025-12-03 00:06:59.927182 | 
2025-12-03 00:06:59.927239 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-03 00:07:00.281919 | controller | ok
2025-12-03 00:07:00.302051 | 
2025-12-03 00:07:00.302178 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-03 00:07:02.079708 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-03 00:07:02.089100 | 
2025-12-03 00:07:02.089286 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-03 00:07:02.645990 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.661224 | 
2025-12-03 00:07:02.661376 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-03 00:07:02.698775 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.732647 | 
2025-12-03 00:07:02.732930 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-03 00:07:02.771516 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.782230 | 
2025-12-03 00:07:02.782336 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-03 00:07:02.808848 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.820315 | 
2025-12-03 00:07:02.820422 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-03 00:07:02.847033 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.857026 | 
2025-12-03 00:07:02.857126 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-03 00:07:02.883711 | controller | skipping: Conditional result was False
2025-12-03 00:07:02.900933 | 
2025-12-03 00:07:02.901034 | TASK [Disable Fedora Modular]
2025-12-03 00:07:03.187992 | controller | changed
2025-12-03 00:07:03.203227 | 
2025-12-03 00:07:03.203385 | TASK [Enable EPEL]
2025-12-03 00:07:03.230390 | controller | skipping: Conditional result was False
2025-12-03 00:07:03.239473 | 
2025-12-03 00:07:03.239582 | TASK [Register the RHEL node]
2025-12-03 00:07:03.793791 | 
2025-12-03 00:07:03.794050 | TASK [Show the subscription-manager status]
2025-12-03 00:07:04.374959 | controller | skipping: Conditional result was False
2025-12-03 00:07:04.381512 | 
2025-12-03 00:07:04.381579 | TASK [Enable EPEL on RHEL]
2025-12-03 00:07:04.913834 | controller | skipping: Conditional result was False
2025-12-03 00:07:04.923094 | 
2025-12-03 00:07:04.923202 | TASK [Install git and tox]
2025-12-03 00:08:28.877900 | controller | changed
2025-12-03 00:08:28.891495 | 
2025-12-03 00:08:28.891629 | TASK [include_role : prepare-workspace]
2025-12-03 00:08:28.935857 | controller | ok
2025-12-03 00:08:28.973522 | 
2025-12-03 00:08:28.973697 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-03 00:08:29.236923 | controller | ok
2025-12-03 00:08:29.252287 | 
2025-12-03 00:08:29.252420 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-03 00:08:41.910986 | controller | Output suppressed because no_log was given
2025-12-03 00:08:41.920926 | 
2025-12-03 00:08:41.920987 | TASK [include_role : prepare-workspace-openshift]
2025-12-03 00:08:41.945656 | controller | skipping: Conditional result was False
2025-12-03 00:08:41.976087 | 
2025-12-03 00:08:41.976140 | PLAY [all:!appliance]
2025-12-03 00:08:41.991215 | 
2025-12-03 00:08:41.991277 | TASK [Run add-build-sshkey role (RSA)]
2025-12-03 00:08:42.021199 | controller | ok
2025-12-03 00:08:42.035918 | 
2025-12-03 00:08:42.035979 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-03 00:08:42.304089 | controller -> localhost | ok
2025-12-03 00:08:42.310796 | 
2025-12-03 00:08:42.310859 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-03 00:08:42.352648 | controller | ok
2025-12-03 00:08:42.373519 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-03 00:08:42.383068 | 
2025-12-03 00:08:42.383154 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-03 00:08:42.987729 | controller -> localhost | Generating public/private rsa key pair.
2025-12-03 00:08:42.987959 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_rsa.
2025-12-03 00:08:42.987989 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_rsa.pub.
2025-12-03 00:08:42.988011 | controller -> localhost | The key fingerprint is:
2025-12-03 00:08:42.988031 | controller -> localhost | SHA256:oXBzgtu5GKv8dllu0XEhEc71s/3nACIkyIFxqWmlivQ zuul-build-sshkey
2025-12-03 00:08:42.988050 | controller -> localhost | The key's randomart image is:
2025-12-03 00:08:42.988068 | controller -> localhost | +---[RSA 2048]----+
2025-12-03 00:08:42.988087 | controller -> localhost | |  .oo.    oo.    |
2025-12-03 00:08:42.988105 | controller -> localhost | |  .oo+   o....   |
2025-12-03 00:08:42.988124 | controller -> localhost | |   == = + o. .o  |
2025-12-03 00:08:42.988141 | controller -> localhost | | .=  = O .. .  + |
2025-12-03 00:08:42.988159 | controller -> localhost | |oo. o + S..o. . .|
2025-12-03 00:08:42.988197 | controller -> localhost | |o  E + .o... .  .|
2025-12-03 00:08:42.988223 | controller -> localhost | |    o .+ .    . o|
2025-12-03 00:08:42.988242 | controller -> localhost | | . .. o o      o.|
2025-12-03 00:08:42.988259 | controller -> localhost | |  oo.. .        .|
2025-12-03 00:08:42.988279 | controller -> localhost | +----[SHA256]-----+
2025-12-03 00:08:42.988338 | controller -> localhost | ok: Runtime: 0:00:00.227715
2025-12-03 00:08:42.995834 | 
2025-12-03 00:08:42.995912 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-03 00:08:43.027881 | controller | ok
2025-12-03 00:08:43.037845 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-03 00:08:43.047448 | 
2025-12-03 00:08:43.047542 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-03 00:08:43.072406 | controller | skipping: Conditional result was False
2025-12-03 00:08:43.080746 | 
2025-12-03 00:08:43.080847 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-03 00:08:43.527620 | controller | changed
2025-12-03 00:08:43.541128 | 
2025-12-03 00:08:43.541232 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-03 00:08:43.758740 | controller | ok
2025-12-03 00:08:43.767077 | 
2025-12-03 00:08:43.767195 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-03 00:08:44.420095 | controller | changed
2025-12-03 00:08:44.433573 | 
2025-12-03 00:08:44.433772 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-03 00:08:45.088214 | controller | changed
2025-12-03 00:08:45.101006 | 
2025-12-03 00:08:45.101153 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-03 00:08:45.127377 | controller | skipping: Conditional result was False
2025-12-03 00:08:45.137757 | 
2025-12-03 00:08:45.137855 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-03 00:08:45.556800 | controller -> localhost | changed
2025-12-03 00:08:45.570035 | 
2025-12-03 00:08:45.570162 | TASK [add-build-sshkey : Add back temp key]
2025-12-03 00:08:45.861697 | controller -> localhost | Identity added: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_rsa (zuul-build-sshkey)
2025-12-03 00:08:45.861890 | controller -> localhost | ok: Runtime: 0:00:00.008014
2025-12-03 00:08:45.868503 | 
2025-12-03 00:08:45.868582 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-03 00:08:46.234902 | controller | ok
2025-12-03 00:08:46.242950 | 
2025-12-03 00:08:46.243049 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-03 00:08:46.269940 | controller | skipping: Conditional result was False
2025-12-03 00:08:46.291513 | 
2025-12-03 00:08:46.291628 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-03 00:08:46.325947 | controller | ok
2025-12-03 00:08:46.351014 | 
2025-12-03 00:08:46.351143 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-03 00:08:46.613868 | controller -> localhost | ok
2025-12-03 00:08:46.631955 | 
2025-12-03 00:08:46.632209 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-03 00:08:46.669436 | controller | ok
2025-12-03 00:08:46.685035 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-03 00:08:46.694934 | 
2025-12-03 00:08:46.695045 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-03 00:08:46.956049 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-03 00:08:46.956265 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_ecdsa.
2025-12-03 00:08:46.956297 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_ecdsa.pub.
2025-12-03 00:08:46.956326 | controller -> localhost | The key fingerprint is:
2025-12-03 00:08:46.956346 | controller -> localhost | SHA256:k15tzQehfAmMoRWiO/olZArlE6YmQkNMUdgp0MFeRdA zuul-build-sshkey
2025-12-03 00:08:46.956365 | controller -> localhost | The key's randomart image is:
2025-12-03 00:08:46.956385 | controller -> localhost | +---[ECDSA 521]---+
2025-12-03 00:08:46.956403 | controller -> localhost | |=**oo=o . +=. .  |
2025-12-03 00:08:46.956421 | controller -> localhost | |.+oo. E. +...o o |
2025-12-03 00:08:46.956438 | controller -> localhost | | +..+ . .   o +  |
2025-12-03 00:08:46.956456 | controller -> localhost | |. o= . . . . + . |
2025-12-03 00:08:46.956473 | controller -> localhost | |o + o = S . o o .|
2025-12-03 00:08:46.956490 | controller -> localhost | |.o . * o o .   . |
2025-12-03 00:08:46.956507 | controller -> localhost | |    o . o        |
2025-12-03 00:08:46.956524 | controller -> localhost | |     . o         |
2025-12-03 00:08:46.956541 | controller -> localhost | |      .          |
2025-12-03 00:08:46.956558 | controller -> localhost | +----[SHA256]-----+
2025-12-03 00:08:46.956609 | controller -> localhost | ok: Runtime: 0:00:00.007609
2025-12-03 00:08:46.963710 | 
2025-12-03 00:08:46.963790 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-03 00:08:46.984014 | controller | ok
2025-12-03 00:08:46.992351 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-03 00:08:47.001467 | 
2025-12-03 00:08:47.001537 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-03 00:08:47.015514 | controller | skipping: Conditional result was False
2025-12-03 00:08:47.023199 | 
2025-12-03 00:08:47.023314 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-03 00:08:47.288804 | controller | changed
2025-12-03 00:08:47.301022 | 
2025-12-03 00:08:47.301153 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-03 00:08:47.530362 | controller | ok
2025-12-03 00:08:47.540963 | 
2025-12-03 00:08:47.541056 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-03 00:08:48.164356 | controller | changed
2025-12-03 00:08:48.171789 | 
2025-12-03 00:08:48.171893 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-03 00:08:48.794778 | controller | changed
2025-12-03 00:08:48.811546 | 
2025-12-03 00:08:48.811730 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-03 00:08:48.947335 | controller | skipping: Conditional result was False
2025-12-03 00:08:48.956345 | 
2025-12-03 00:08:48.956481 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-03 00:08:49.310504 | controller -> localhost | changed
2025-12-03 00:08:49.323280 | 
2025-12-03 00:08:49.323409 | TASK [add-build-sshkey : Add back temp key]
2025-12-03 00:08:49.624216 | controller -> localhost | Identity added: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/62b0e0be5e4341acbde1db009b4362ba_id_ecdsa (zuul-build-sshkey)
2025-12-03 00:08:49.624430 | controller -> localhost | ok: Runtime: 0:00:00.009275
2025-12-03 00:08:49.632148 | 
2025-12-03 00:08:49.632234 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-03 00:08:49.842325 | controller | ok
2025-12-03 00:08:49.852105 | 
2025-12-03 00:08:49.852357 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-03 00:08:49.900964 | controller | skipping: Conditional result was False
2025-12-03 00:08:49.918705 | 
2025-12-03 00:08:49.918840 | TASK [include_role : remove-zuul-sshkey]
2025-12-03 00:08:49.944759 | controller | skipping: Conditional result was False
2025-12-03 00:08:49.956647 | 
2025-12-03 00:08:49.956815 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-03 00:08:50.204033 | controller | ok: "logs"
2025-12-03 00:08:50.204620 | controller | ok: All items complete
2025-12-03 00:08:50.205418 | 
2025-12-03 00:08:50.388472 | controller | ok: "artifacts"
2025-12-03 00:08:50.591162 | controller | ok: "docs"
2025-12-03 00:08:50.613079 | 
2025-12-03 00:08:50.613228 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-03 00:08:50.861878 | controller | changed: "logs"
2025-12-03 00:08:51.054014 | controller | changed: "artifacts"
2025-12-03 00:08:51.245925 | controller | changed: "docs"
2025-12-03 00:08:51.283374 | 
2025-12-03 00:08:51.283471 | PLAY RECAP
2025-12-03 00:08:51.283513 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-03 00:08:51.283539 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-03 00:08:51.283558 | 
2025-12-03 00:08:51.494877 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-03 00:08:51.495994 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 00:08:52.106963 | 
2025-12-03 00:08:52.107101 | PLAY [all]
2025-12-03 00:08:52.133043 | 
2025-12-03 00:08:52.133176 | TASK [Install binary dependencies]
2025-12-03 00:08:52.195523 | controller | ok
2025-12-03 00:08:52.223116 | 
2025-12-03 00:08:52.223292 | TASK [bindep : Include find tasks]
2025-12-03 00:08:52.253880 | controller | ok
2025-12-03 00:08:52.261660 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-03 00:08:52.268825 | 
2025-12-03 00:08:52.268923 | TASK [bindep : Look for bindep.txt]
2025-12-03 00:08:52.700787 | controller | ok
2025-12-03 00:08:52.709706 | 
2025-12-03 00:08:52.709810 | TASK [bindep : Define bindep_file fact]
2025-12-03 00:08:52.737687 | controller | skipping: Conditional result was False
2025-12-03 00:08:52.744179 | 
2025-12-03 00:08:52.744307 | TASK [bindep : Look for other-requirements.txt]
2025-12-03 00:08:52.970135 | controller | ok
2025-12-03 00:08:52.976534 | 
2025-12-03 00:08:52.976619 | TASK [bindep : Define bindep_file fact]
2025-12-03 00:08:53.003893 | controller | skipping: Conditional result was False
2025-12-03 00:08:53.011208 | 
2025-12-03 00:08:53.011355 | TASK [bindep : Look for bindep fallback file]
2025-12-03 00:08:53.070464 | controller | skipping: Conditional result was False
2025-12-03 00:08:53.078369 | 
2025-12-03 00:08:53.078485 | TASK [bindep : Define bindep_file fact]
2025-12-03 00:08:53.114283 | controller | skipping: Conditional result was False
2025-12-03 00:08:53.121771 | 
2025-12-03 00:08:53.121858 | TASK [bindep : Include bindep tasks]
2025-12-03 00:08:53.147069 | controller | skipping: Conditional result was False
2025-12-03 00:08:53.155208 | 
2025-12-03 00:08:53.155296 | TASK [bindep : Include install tasks]
2025-12-03 00:08:53.181599 | controller | skipping: Conditional result was False
2025-12-03 00:08:53.189160 | 
2025-12-03 00:08:53.189238 | LOOP [bindep : Include package tasks]
2025-12-03 00:08:53.251366 | 
2025-12-03 00:08:53.251602 | TASK [Run test-setup role]
2025-12-03 00:08:53.274934 | controller | ok
2025-12-03 00:08:53.291542 | 
2025-12-03 00:08:53.291647 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-03 00:08:53.498181 | controller | ok
2025-12-03 00:08:53.507049 | 
2025-12-03 00:08:53.507177 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-03 00:08:54.049917 | controller | skipping: Conditional result was False
2025-12-03 00:08:54.099962 | 
2025-12-03 00:08:54.100044 | PLAY RECAP
2025-12-03 00:08:54.100102 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-03 00:08:54.100130 | 
2025-12-03 00:08:54.204969 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 00:08:54.205885 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-03 00:08:54.826240 | 
2025-12-03 00:08:54.826373 | PLAY [controller]
2025-12-03 00:08:54.847301 | 
2025-12-03 00:08:54.847416 | TASK [Create the /root directory]
2025-12-03 00:08:55.270627 | controller | ok
2025-12-03 00:08:55.281432 | 
2025-12-03 00:08:55.281546 | TASK [Install glibc-langpack-en]
2025-12-03 00:08:59.259841 | controller | ok: Nothing to do
2025-12-03 00:08:59.268598 | 
2025-12-03 00:08:59.268733 | TASK [Ensure controller directory exists]
2025-12-03 00:08:59.493314 | controller | changed
2025-12-03 00:08:59.508364 | 
2025-12-03 00:08:59.508576 | TASK [Install container runtime]
2025-12-03 00:08:59.566982 | controller | ok
2025-12-03 00:08:59.614761 | 
2025-12-03 00:08:59.614886 | LOOP [ensure-podman : Find distribution installation]
2025-12-03 00:08:59.681162 | controller | ok: "/var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-03 00:08:59.703064 | controller | included: /var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-03 00:08:59.717337 | 
2025-12-03 00:08:59.717490 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-03 00:10:06.613511 | controller | changed
2025-12-03 00:10:06.630258 | 
2025-12-03 00:10:06.630483 | TASK [ensure-podman : Fetch podman version]
2025-12-03 00:10:07.243215 | controller | Client:       Podman Engine
2025-12-03 00:10:07.243321 | controller | Version:      4.6.2
2025-12-03 00:10:07.243367 | controller | API Version:  4.6.2
2025-12-03 00:10:07.243409 | controller | Go Version:   go1.19.12
2025-12-03 00:10:07.243460 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-03 00:10:07.243504 | controller | OS/Arch:      linux/amd64
2025-12-03 00:10:07.685126 | controller | ok: Runtime: 0:00:00.225249
2025-12-03 00:10:07.701041 | 
2025-12-03 00:10:07.701202 | TASK [ensure-podman : Print podman version installed]
2025-12-03 00:10:07.745024 | Podman version: Client:       Podman Engine
2025-12-03 00:10:07.745326 | Version:      4.6.2
2025-12-03 00:10:07.745387 | API Version:  4.6.2
2025-12-03 00:10:07.745432 | Go Version:   go1.19.12
2025-12-03 00:10:07.745471 | Built:        Mon Aug 28 19:38:31 2023
2025-12-03 00:10:07.745511 | OS/Arch:      linux/amd64
2025-12-03 00:10:07.758575 | 
2025-12-03 00:10:07.758785 | TASK [ensure-podman : Validate podman engine]
2025-12-03 00:10:08.306558 | controller | skipping: Conditional result was False
2025-12-03 00:10:08.321727 | 
2025-12-03 00:10:08.321980 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-03 00:10:08.340435 | controller | skipping: Conditional result was False
2025-12-03 00:10:08.370691 | 
2025-12-03 00:10:08.371004 | TASK [Ensure python3.8 is present]
2025-12-03 00:10:08.389285 | controller | skipping: Conditional result was False
2025-12-03 00:10:08.401222 | 
2025-12-03 00:10:08.401475 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-03 00:10:08.428771 | controller | ok
2025-12-03 00:10:08.460464 | 
2025-12-03 00:10:08.460700 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-03 00:10:09.854525 | controller | ok: Nothing to do
2025-12-03 00:10:09.867475 | 
2025-12-03 00:10:09.867620 | TASK [our-ensure-python : Also install python3-devel]
2025-12-03 00:10:19.307270 | controller | changed
2025-12-03 00:10:19.332286 | 
2025-12-03 00:10:19.332423 | TASK [Run ensure-virtualenv role]
2025-12-03 00:10:19.367791 | controller | ok
2025-12-03 00:10:19.406829 | 
2025-12-03 00:10:19.407023 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-03 00:10:19.691076 | controller | /usr/bin/virtualenv
2025-12-03 00:10:19.999365 | controller | ok: Runtime: 0:00:00.004911
2025-12-03 00:10:20.012880 | 
2025-12-03 00:10:20.013019 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-03 00:10:20.056040 | controller | skipping: Conditional result was False
2025-12-03 00:10:20.056559 | controller | ok: All items complete
2025-12-03 00:10:20.056645 | 
2025-12-03 00:10:20.092166 | 
2025-12-03 00:10:20.092472 | TASK [Find the full path of the Python interpreter]
2025-12-03 00:10:20.359401 | controller | /usr/bin/python3
2025-12-03 00:10:20.660520 | controller | ok
2025-12-03 00:10:20.675280 | 
2025-12-03 00:10:20.675517 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-03 00:10:21.764674 | controller | created virtual environment CPython3.11.0.final.0-64 in 570ms
2025-12-03 00:10:21.782704 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-03 00:10:21.782743 | 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-03 00:10:21.782753 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-03 00:10:21.782768 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-03 00:10:22.235485 | controller | changed
2025-12-03 00:10:22.250816 | 
2025-12-03 00:10:22.251015 | TASK [Set selinux package]
2025-12-03 00:10:22.292183 | controller | ok
2025-12-03 00:10:22.306793 | 
2025-12-03 00:10:22.307005 | TASK [Set selinux package (Fedora)]
2025-12-03 00:10:22.356007 | controller | ok
2025-12-03 00:10:22.364210 | 
2025-12-03 00:10:22.364355 | TASK [Install selinux into virtualenv]
2025-12-03 00:10:35.927592 | controller | Collecting selinux-please-lie-to-me
2025-12-03 00:10:48.177307 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-03 00:10:48.482726 | controller | Collecting setuptools<50.0.0
2025-12-03 00:10:48.487622 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-03 00:10:48.552923 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.3 MB/s eta 0:00:00
2025-12-03 00:10:48.633221 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-03 00:10:48.633328 | controller |   Attempting uninstall: setuptools
2025-12-03 00:10:48.635652 | controller |     Found existing installation: setuptools 62.6.0
2025-12-03 00:10:48.694817 | controller |     Uninstalling setuptools-62.6.0:
2025-12-03 00:10:48.703106 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-03 00:10:49.057102 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-03 00:11:00.542167 | controller |
2025-12-03 00:11:00.622079 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-03 00:11:00.622137 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-03 00:11:00.929199 | controller | ok: Runtime: 0:00:38.025436
2025-12-03 00:11:00.945745 | 
2025-12-03 00:11:00.945884 | TASK [Install pytest-forked into virtualenv]
2025-12-03 00:11:12.788010 | controller | Collecting pytest-forked
2025-12-03 00:11:46.868919 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-03 00:11:46.927882 | controller | Collecting py
2025-12-03 00:11:46.931413 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-03 00:11:46.956803 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.4 MB/s eta 0:00:00
2025-12-03 00:11:47.068929 | controller | Collecting pytest>=3.10
2025-12-03 00:11:47.073940 | controller |   Downloading pytest-9.0.1-py3-none-any.whl (373 kB)
2025-12-03 00:11:47.091779 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 25.5 MB/s eta 0:00:00
2025-12-03 00:11:47.134950 | controller | Collecting iniconfig>=1.0.1
2025-12-03 00:11:47.139055 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-03 00:11:47.178896 | controller | Collecting packaging>=22
2025-12-03 00:11:47.184497 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-03 00:11:47.191069 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 14.6 MB/s eta 0:00:00
2025-12-03 00:11:47.224800 | controller | Collecting pluggy<2,>=1.5
2025-12-03 00:11:47.228269 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-03 00:11:47.275468 | controller | Collecting pygments>=2.7.2
2025-12-03 00:11:47.280608 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-03 00:11:47.300987 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 66.4 MB/s eta 0:00:00
2025-12-03 00:11:47.365078 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-03 00:11:48.545654 | 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-03 00:11:48.554758 | controller |
2025-12-03 00:11:48.632260 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-03 00:11:48.632391 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-03 00:11:49.005957 | controller | ok: Runtime: 0:00:47.489318
2025-12-03 00:11:49.015010 | 
2025-12-03 00:11:49.015207 | TASK [Update pip]
2025-12-03 00:11:49.551785 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-03 00:12:01.993691 | controller | Collecting pip
2025-12-03 00:12:14.309615 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-03 00:12:14.404578 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 19.5 MB/s eta 0:00:00
2025-12-03 00:12:14.469625 | controller | Installing collected packages: pip
2025-12-03 00:12:14.469786 | controller |   Attempting uninstall: pip
2025-12-03 00:12:14.472091 | controller |     Found existing installation: pip 22.2.2
2025-12-03 00:12:14.608500 | controller |     Uninstalling pip-22.2.2:
2025-12-03 00:12:14.623621 | controller |       Successfully uninstalled pip-22.2.2
2025-12-03 00:12:15.470934 | controller | Successfully installed pip-25.3
2025-12-03 00:12:15.590608 | controller | ok: Runtime: 0:00:26.304138
2025-12-03 00:12:15.605521 | 
2025-12-03 00:12:15.605803 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-03 00:12:15.834311 | controller | changed
2025-12-03 00:12:15.848932 | 
2025-12-03 00:12:15.849176 | TASK [Install ansible into virtualenv]
2025-12-03 00:12:16.379719 | controller | Processing ./src/github.com/ansible/ansible
2025-12-03 00:12:16.383085 | controller |   Installing build dependencies: started
2025-12-03 00:12:39.342092 | controller |   Installing build dependencies: finished with status 'done'
2025-12-03 00:12:39.343640 | controller |   Getting requirements to build wheel: started
2025-12-03 00:12:40.104882 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-03 00:12:40.107852 | controller |   Preparing metadata (pyproject.toml): started
2025-12-03 00:12:40.567873 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-03 00:12:40.573229 | 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-03 00:12:40.577304 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-03 00:12:40.914970 | controller | ERROR
2025-12-03 00:12:40.915304 | controller | {
2025-12-03 00:12:40.915348 | controller |   "delta": "0:00:24.567060",
2025-12-03 00:12:40.915370 | controller |   "end": "2025-12-03 00:12:40.658705",
2025-12-03 00:12:40.915389 | controller |   "msg": "non-zero return code",
2025-12-03 00:12:40.915420 | controller |   "rc": 1,
2025-12-03 00:12:40.915436 | controller |   "start": "2025-12-03 00:12:16.091645"
2025-12-03 00:12:40.915452 | controller | }
failure
2025-12-03 00:12:40.919302 | 
2025-12-03 00:12:40.919352 | PLAY RECAP
2025-12-03 00:12:40.919395 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-03 00:12:40.919415 | 
2025-12-03 00:12:41.111031 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-03 00:12:41.112226 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 00:12:41.757377 | 
2025-12-03 00:12:41.757524 | PLAY [all]
2025-12-03 00:12:41.780751 | 
2025-12-03 00:12:41.780952 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-03 00:12:42.113161 | controller | changed: non-zero return code
2025-12-03 00:12:42.126736 | 
2025-12-03 00:12:42.126919 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-03 00:12:42.146545 | controller | skipping: Conditional result was False
2025-12-03 00:12:42.163416 | 
2025-12-03 00:12:42.163610 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-03 00:12:42.207553 | 
2025-12-03 00:12:42.208141 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-03 00:12:42.246623 | 
2025-12-03 00:12:42.246924 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-03 00:12:42.274618 | controller | skipping: Conditional result was False
2025-12-03 00:12:42.286391 | 
2025-12-03 00:12:42.286526 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-03 00:12:42.323481 | 
2025-12-03 00:12:42.323749 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-03 00:12:42.350617 | controller | skipping: Conditional result was False
2025-12-03 00:12:42.359355 | 
2025-12-03 00:12:42.359518 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-03 00:12:42.386930 | controller | skipping: Conditional result was False
2025-12-03 00:12:42.397235 | 
2025-12-03 00:12:42.397399 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-03 00:12:42.424840 | controller | skipping: Conditional result was False
2025-12-03 00:12:42.457333 | 
2025-12-03 00:12:42.457478 | PLAY RECAP
2025-12-03 00:12:42.457527 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-03 00:12:42.457546 | 
2025-12-03 00:12:42.645443 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 00:12:42.647695 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-03 00:12:43.283040 | 
2025-12-03 00:12:43.283176 | PLAY [all:!appliance*]
2025-12-03 00:12:43.305383 | 
2025-12-03 00:12:43.305562 | TASK [unregister the node]
2025-12-03 00:12:43.842951 | controller | skipping: Conditional result was False
2025-12-03 00:12:43.849371 | 
2025-12-03 00:12:43.849464 | TASK [include_role : fetch-output]
2025-12-03 00:12:43.894026 | controller | ok
2025-12-03 00:12:43.925488 | 
2025-12-03 00:12:43.925649 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-03 00:12:43.993257 | controller | skipping: Conditional result was False
2025-12-03 00:12:44.001012 | 
2025-12-03 00:12:44.001111 | TASK [fetch-output : Set log path for single node]
2025-12-03 00:12:44.062861 | controller | ok
2025-12-03 00:12:44.068350 | 
2025-12-03 00:12:44.068420 | LOOP [fetch-output : Ensure local output dirs]
2025-12-03 00:12:44.581623 | controller -> localhost | ok: "/var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/logs"
2025-12-03 00:12:44.810690 | controller -> localhost | changed: "/var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/artifacts"
2025-12-03 00:12:45.075038 | controller -> localhost | changed: "/var/lib/zuul/builds/62b0e0be5e4341acbde1db009b4362ba/work/docs"
2025-12-03 00:12:45.092175 | 
2025-12-03 00:12:45.092401 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-03 00:12:45.917190 | controller | changed:
2025-12-03 00:12:45.917694 | controller | .d..t...... ./
2025-12-03 00:12:45.917780 | controller | cd+++++++++ controller/
2025-12-03 00:12:45.917855 | controller | changed: All items complete
2025-12-03 00:12:45.917900 | 
2025-12-03 00:12:46.460915 | controller | changed: .d..t...... ./
2025-12-03 00:12:46.966002 | controller | changed: .d..t...... ./
2025-12-03 00:12:46.994646 | 
2025-12-03 00:12:46.994876 | TASK [include_role : fetch-output-openshift]
2025-12-03 00:12:47.021076 | controller | skipping: Conditional result was False
2025-12-03 00:12:47.030851 | 
2025-12-03 00:12:47.030967 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-03 00:12:47.078412 | controller | skipping: Conditional result was False
2025-12-03 00:12:47.089348 | controller | skipping: Conditional result was False
2025-12-03 00:12:47.133692 | 
2025-12-03 00:12:47.133890 | PLAY [localhost]
2025-12-03 00:12:47.147896 | 
2025-12-03 00:12:47.148063 | TASK [Run Zuul manifest role]
2025-12-03 00:12:47.170422 | localhost | ok
2025-12-03 00:12:47.184040 | 
2025-12-03 00:12:47.184186 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-03 00:12:47.581905 | localhost | changed
2025-12-03 00:12:47.586869 | 
2025-12-03 00:12:47.586946 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-03 00:12:47.626630 | localhost | ok
2025-12-03 00:12:47.635050 | 
2025-12-03 00:12:47.635132 | TASK [Set zuul-log-path fact]
2025-12-03 00:12:47.653795 | localhost | ok
2025-12-03 00:12:47.668034 | 
2025-12-03 00:12:47.668128 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 00:12:47.697198 | localhost | ok
2025-12-03 00:12:47.705341 | 
2025-12-03 00:12:47.705408 | LOOP [Run upload-logs-swift role]
2025-12-03 00:12:47.731508 | localhost | Output suppressed because no_log was given
2025-12-03 00:12:47.756128 | 
2025-12-03 00:12:47.756257 | TASK [Set zuul-log-path fact]
2025-12-03 00:12:47.791645 | localhost | skipping: Conditional result was False
2025-12-03 00:12:47.798530 | 
2025-12-03 00:12:47.798622 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-03 00:12:48.274256 | localhost -> localhost | ok: Runtime: 0:00:00.006505
2025-12-03 00:12:48.282976 | 
2025-12-03 00:12:48.283124 | TASK [upload-logs-swift : Upload logs to swift]