2025-12-28 00:14:57.042087 | Job console starting...
2025-12-28 00:14:57.052108 | Updating repositories
2025-12-28 00:14:57.180864 | Preparing job workspace
2025-12-28 00:15:01.601447 | Running Ansible setup...
2025-12-28 00:15:06.477669 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-28 00:15:07.147852 | 
2025-12-28 00:15:07.148038 | PLAY [localhost]
2025-12-28 00:15:07.157074 | 
2025-12-28 00:15:07.157191 | TASK [Gathering Facts]
2025-12-28 00:15:08.144331 | localhost | ok
2025-12-28 00:15:08.163612 | 
2025-12-28 00:15:08.163774 | TASK [Setup log path fact]
2025-12-28 00:15:08.182905 | localhost | ok
2025-12-28 00:15:08.207345 | 
2025-12-28 00:15:08.207551 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-28 00:15:08.238220 | localhost | ok
2025-12-28 00:15:08.249758 | 
2025-12-28 00:15:08.249877 | TASK [emit-job-header : Print job information]
2025-12-28 00:15:08.289002 | # Job Information
2025-12-28 00:15:08.289223 | Ansible Version: 2.15.12
2025-12-28 00:15:08.289258 | Job: ansible-test-sanity-docker-devel
2025-12-28 00:15:08.289281 | Pipeline: periodic
2025-12-28 00:15:08.289301 | Executor: ze01.softwarefactory-project.io
2025-12-28 00:15:08.289321 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-28 00:15:08.289346 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/9f7/ansible/9f75db4181b1425cb61fbcdd5246d621/
2025-12-28 00:15:08.289365 | Event ID: 3f53bd7375e24114bd964e912e0e7186
2025-12-28 00:15:08.293109 | 
2025-12-28 00:15:08.293182 | LOOP [emit-job-header : Print node information]
2025-12-28 00:15:08.395679 | localhost | ok:
2025-12-28 00:15:08.395928 | localhost | # Node Information
2025-12-28 00:15:08.395967 | localhost | Inventory Hostname: controller
2025-12-28 00:15:08.395997 | localhost | Hostname: np0005571759
2025-12-28 00:15:08.396175 | localhost | Username: zuul
2025-12-28 00:15:08.396221 | localhost | Distro: Fedora 37
2025-12-28 00:15:08.396250 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-28 00:15:08.396275 | localhost | Region: ca-ymq-1
2025-12-28 00:15:08.396299 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-28 00:15:08.396325 | localhost | Product Name: OpenStack Nova
2025-12-28 00:15:08.396351 | localhost | Interface IP: 162.253.55.186
2025-12-28 00:15:08.413093 | 
2025-12-28 00:15:08.413246 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-28 00:15:08.877959 | localhost -> localhost | changed
2025-12-28 00:15:08.885247 | 
2025-12-28 00:15:08.885366 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-28 00:15:09.811598 | localhost -> localhost | changed
2025-12-28 00:15:09.832134 | 
2025-12-28 00:15:09.832203 | PLAY [all:!appliance*]
2025-12-28 00:15:09.848395 | 
2025-12-28 00:15:09.848504 | TASK [include_role : start-zuul-console]
2025-12-28 00:15:09.867926 | controller | ok
2025-12-28 00:15:09.883412 | 
2025-12-28 00:15:09.883528 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-28 00:15:10.242084 | controller | ok
2025-12-28 00:15:10.282238 | 
2025-12-28 00:15:10.282392 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-28 00:15:11.264561 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-28 00:15:11.272258 | 
2025-12-28 00:15:11.272406 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-28 00:15:11.811102 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.821750 | 
2025-12-28 00:15:11.821931 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-28 00:15:11.837347 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.847203 | 
2025-12-28 00:15:11.847379 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-28 00:15:11.873770 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.883398 | 
2025-12-28 00:15:11.883613 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-28 00:15:11.900947 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.908403 | 
2025-12-28 00:15:11.908535 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-28 00:15:11.932599 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.941687 | 
2025-12-28 00:15:11.941846 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-28 00:15:11.966223 | controller | skipping: Conditional result was False
2025-12-28 00:15:11.980779 | 
2025-12-28 00:15:11.980922 | TASK [Disable Fedora Modular]
2025-12-28 00:15:12.219531 | controller | changed
2025-12-28 00:15:12.226845 | 
2025-12-28 00:15:12.226993 | TASK [Enable EPEL]
2025-12-28 00:15:12.252216 | controller | skipping: Conditional result was False
2025-12-28 00:15:12.260598 | 
2025-12-28 00:15:12.260712 | TASK [Register the RHEL node]
2025-12-28 00:15:12.802541 | 
2025-12-28 00:15:12.802732 | TASK [Show the subscription-manager status]
2025-12-28 00:15:13.372514 | controller | skipping: Conditional result was False
2025-12-28 00:15:13.392726 | 
2025-12-28 00:15:13.392905 | TASK [Enable EPEL on RHEL]
2025-12-28 00:15:13.946815 | controller | skipping: Conditional result was False
2025-12-28 00:15:13.954713 | 
2025-12-28 00:15:13.954834 | TASK [Install git and tox]
2025-12-28 00:16:55.790866 | controller | changed
2025-12-28 00:16:55.798710 | 
2025-12-28 00:16:55.798861 | TASK [include_role : prepare-workspace]
2025-12-28 00:16:55.820031 | controller | ok
2025-12-28 00:16:55.846234 | 
2025-12-28 00:16:55.846399 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-28 00:16:56.064248 | controller | ok
2025-12-28 00:16:56.071645 | 
2025-12-28 00:16:56.071763 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-28 00:17:10.834730 | controller | Output suppressed because no_log was given
2025-12-28 00:17:10.860264 | 
2025-12-28 00:17:10.860450 | TASK [include_role : prepare-workspace-openshift]
2025-12-28 00:17:10.887122 | controller | skipping: Conditional result was False
2025-12-28 00:17:10.931121 | 
2025-12-28 00:17:10.931261 | PLAY [all:!appliance]
2025-12-28 00:17:10.959703 | 
2025-12-28 00:17:10.959863 | TASK [Run add-build-sshkey role (RSA)]
2025-12-28 00:17:10.991668 | controller | ok
2025-12-28 00:17:11.010196 | 
2025-12-28 00:17:11.010332 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-28 00:17:11.279663 | controller -> localhost | ok
2025-12-28 00:17:11.286763 | 
2025-12-28 00:17:11.286871 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-28 00:17:11.317460 | controller | ok
2025-12-28 00:17:11.368672 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-28 00:17:11.374952 | 
2025-12-28 00:17:11.375043 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-28 00:17:12.023847 | controller -> localhost | Generating public/private rsa key pair.
2025-12-28 00:17:12.024138 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_rsa.
2025-12-28 00:17:12.024171 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_rsa.pub.
2025-12-28 00:17:12.024215 | controller -> localhost | The key fingerprint is:
2025-12-28 00:17:12.024238 | controller -> localhost | SHA256:gTpHqRmnLxIfFOJ/zOnw8snAJorC8WJvFpV/IC+bvY0 zuul-build-sshkey
2025-12-28 00:17:12.024259 | controller -> localhost | The key's randomart image is:
2025-12-28 00:17:12.024302 | controller -> localhost | +---[RSA 2048]----+
2025-12-28 00:17:12.024321 | controller -> localhost | |  . .            |
2025-12-28 00:17:12.024340 | controller -> localhost | | . . . o         |
2025-12-28 00:17:12.024382 | controller -> localhost | |  . o * .        |
2025-12-28 00:17:12.024403 | controller -> localhost | |   o # o .       |
2025-12-28 00:17:12.024420 | controller -> localhost | |  . @ X S        |
2025-12-28 00:17:12.024474 | controller -> localhost | | . = @ o .       |
2025-12-28 00:17:12.024501 | controller -> localhost | |. = O O .        |
2025-12-28 00:17:12.024542 | controller -> localhost | |o= B O oo        |
2025-12-28 00:17:12.024565 | controller -> localhost | |= =.  +E..       |
2025-12-28 00:17:12.024585 | controller -> localhost | +----[SHA256]-----+
2025-12-28 00:17:12.024658 | controller -> localhost | ok: Runtime: 0:00:00.192491
2025-12-28 00:17:12.031990 | 
2025-12-28 00:17:12.032141 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-28 00:17:12.062515 | controller | ok
2025-12-28 00:17:12.075265 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-28 00:17:12.084977 | 
2025-12-28 00:17:12.085103 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-28 00:17:12.099826 | controller | skipping: Conditional result was False
2025-12-28 00:17:12.106994 | 
2025-12-28 00:17:12.107105 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-28 00:17:12.596327 | controller | changed
2025-12-28 00:17:12.609454 | 
2025-12-28 00:17:12.609648 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-28 00:17:12.857254 | controller | ok
2025-12-28 00:17:12.874202 | 
2025-12-28 00:17:12.874420 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-28 00:17:13.533455 | controller | changed
2025-12-28 00:17:13.550292 | 
2025-12-28 00:17:13.550872 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-28 00:17:14.217937 | controller | changed
2025-12-28 00:17:14.235383 | 
2025-12-28 00:17:14.235512 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-28 00:17:14.264855 | controller | skipping: Conditional result was False
2025-12-28 00:17:14.275960 | 
2025-12-28 00:17:14.276111 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-28 00:17:14.730852 | controller -> localhost | changed
2025-12-28 00:17:14.750818 | 
2025-12-28 00:17:14.750989 | TASK [add-build-sshkey : Add back temp key]
2025-12-28 00:17:15.062977 | controller -> localhost | Identity added: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_rsa (zuul-build-sshkey)
2025-12-28 00:17:15.063248 | controller -> localhost | ok: Runtime: 0:00:00.009002
2025-12-28 00:17:15.070933 | 
2025-12-28 00:17:15.071038 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-28 00:17:15.427473 | controller | ok
2025-12-28 00:17:15.433083 | 
2025-12-28 00:17:15.433163 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-28 00:17:15.457867 | controller | skipping: Conditional result was False
2025-12-28 00:17:15.479537 | 
2025-12-28 00:17:15.479695 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-28 00:17:15.503521 | controller | ok
2025-12-28 00:17:15.526741 | 
2025-12-28 00:17:15.526895 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-28 00:17:15.789066 | controller -> localhost | ok
2025-12-28 00:17:15.799170 | 
2025-12-28 00:17:15.799289 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-28 00:17:15.827657 | controller | ok
2025-12-28 00:17:15.842979 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-28 00:17:15.853897 | 
2025-12-28 00:17:15.854006 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-28 00:17:16.165569 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-28 00:17:16.165968 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_ecdsa.
2025-12-28 00:17:16.166120 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_ecdsa.pub.
2025-12-28 00:17:16.166202 | controller -> localhost | The key fingerprint is:
2025-12-28 00:17:16.166255 | controller -> localhost | SHA256:Y011OIettdxyuUqRrI8YUdYPi/AxxUH4uyQOVZk21vM zuul-build-sshkey
2025-12-28 00:17:16.166302 | controller -> localhost | The key's randomart image is:
2025-12-28 00:17:16.166349 | controller -> localhost | +---[ECDSA 521]---+
2025-12-28 00:17:16.166395 | controller -> localhost | |            BB*  |
2025-12-28 00:17:16.166440 | controller -> localhost | |         . B+%+o |
2025-12-28 00:17:16.166500 | controller -> localhost | |          * X**o+|
2025-12-28 00:17:16.166544 | controller -> localhost | |         + +.*+oE|
2025-12-28 00:17:16.166586 | controller -> localhost | |        S + . oo.|
2025-12-28 00:17:16.166638 | controller -> localhost | |       . + o + . |
2025-12-28 00:17:16.166697 | controller -> localhost | |          = * o  |
2025-12-28 00:17:16.166741 | controller -> localhost | |         . o +   |
2025-12-28 00:17:16.166793 | controller -> localhost | |                 |
2025-12-28 00:17:16.166848 | controller -> localhost | +----[SHA256]-----+
2025-12-28 00:17:16.166967 | controller -> localhost | ok: Runtime: 0:00:00.008805
2025-12-28 00:17:16.183812 | 
2025-12-28 00:17:16.183971 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-28 00:17:16.225962 | controller | ok
2025-12-28 00:17:16.238864 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-28 00:17:16.254696 | 
2025-12-28 00:17:16.254848 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-28 00:17:16.270506 | controller | skipping: Conditional result was False
2025-12-28 00:17:16.281543 | 
2025-12-28 00:17:16.281698 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-28 00:17:16.553961 | controller | changed
2025-12-28 00:17:16.566792 | 
2025-12-28 00:17:16.566932 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-28 00:17:16.790590 | controller | ok
2025-12-28 00:17:16.799442 | 
2025-12-28 00:17:16.799535 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-28 00:17:17.456704 | controller | changed
2025-12-28 00:17:17.466360 | 
2025-12-28 00:17:17.466521 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-28 00:17:18.081805 | controller | changed
2025-12-28 00:17:18.087943 | 
2025-12-28 00:17:18.088039 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-28 00:17:18.123246 | controller | skipping: Conditional result was False
2025-12-28 00:17:18.175505 | 
2025-12-28 00:17:18.175669 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-28 00:17:18.486140 | controller -> localhost | changed
2025-12-28 00:17:18.497879 | 
2025-12-28 00:17:18.497981 | TASK [add-build-sshkey : Add back temp key]
2025-12-28 00:17:18.831276 | controller -> localhost | Identity added: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/9f75db4181b1425cb61fbcdd5246d621_id_ecdsa (zuul-build-sshkey)
2025-12-28 00:17:18.831805 | controller -> localhost | ok: Runtime: 0:00:00.014557
2025-12-28 00:17:18.840517 | 
2025-12-28 00:17:18.840614 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-28 00:17:19.056847 | controller | ok
2025-12-28 00:17:19.072865 | 
2025-12-28 00:17:19.073097 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-28 00:17:19.112138 | controller | skipping: Conditional result was False
2025-12-28 00:17:19.140394 | 
2025-12-28 00:17:19.140595 | TASK [include_role : remove-zuul-sshkey]
2025-12-28 00:17:19.168807 | controller | skipping: Conditional result was False
2025-12-28 00:17:19.179896 | 
2025-12-28 00:17:19.180112 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-28 00:17:19.418558 | controller | ok: "logs"
2025-12-28 00:17:19.418914 | controller | ok: All items complete
2025-12-28 00:17:19.418958 | 
2025-12-28 00:17:19.626492 | controller | ok: "artifacts"
2025-12-28 00:17:19.821822 | controller | ok: "docs"
2025-12-28 00:17:19.837509 | 
2025-12-28 00:17:19.837727 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-28 00:17:20.081600 | controller | changed: "logs"
2025-12-28 00:17:20.274742 | controller | changed: "artifacts"
2025-12-28 00:17:20.465625 | controller | changed: "docs"
2025-12-28 00:17:20.496759 | 
2025-12-28 00:17:20.496892 | PLAY RECAP
2025-12-28 00:17:20.496940 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-28 00:17:20.496966 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-28 00:17:20.496983 | 
2025-12-28 00:17:20.625128 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-28 00:17:20.626111 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-28 00:17:21.347903 | 
2025-12-28 00:17:21.348109 | PLAY [all]
2025-12-28 00:17:21.371632 | 
2025-12-28 00:17:21.371766 | TASK [Install binary dependencies]
2025-12-28 00:17:21.422464 | controller | ok
2025-12-28 00:17:21.443239 | 
2025-12-28 00:17:21.443394 | TASK [bindep : Include find tasks]
2025-12-28 00:17:21.473237 | controller | ok
2025-12-28 00:17:21.503913 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-28 00:17:21.510690 | 
2025-12-28 00:17:21.510774 | TASK [bindep : Look for bindep.txt]
2025-12-28 00:17:21.857969 | controller | ok
2025-12-28 00:17:21.876074 | 
2025-12-28 00:17:21.876247 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:17:21.902522 | controller | skipping: Conditional result was False
2025-12-28 00:17:21.909443 | 
2025-12-28 00:17:21.909542 | TASK [bindep : Look for other-requirements.txt]
2025-12-28 00:17:22.144655 | controller | ok
2025-12-28 00:17:22.151372 | 
2025-12-28 00:17:22.151480 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:17:22.176244 | controller | skipping: Conditional result was False
2025-12-28 00:17:22.185574 | 
2025-12-28 00:17:22.185686 | TASK [bindep : Look for bindep fallback file]
2025-12-28 00:17:22.210726 | controller | skipping: Conditional result was False
2025-12-28 00:17:22.224194 | 
2025-12-28 00:17:22.224299 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:17:22.249566 | controller | skipping: Conditional result was False
2025-12-28 00:17:22.259428 | 
2025-12-28 00:17:22.259534 | TASK [bindep : Include bindep tasks]
2025-12-28 00:17:22.285583 | controller | skipping: Conditional result was False
2025-12-28 00:17:22.295845 | 
2025-12-28 00:17:22.295963 | TASK [bindep : Include install tasks]
2025-12-28 00:17:22.322618 | controller | skipping: Conditional result was False
2025-12-28 00:17:22.334139 | 
2025-12-28 00:17:22.334297 | LOOP [bindep : Include package tasks]
2025-12-28 00:17:22.418033 | 
2025-12-28 00:17:22.418299 | TASK [Run test-setup role]
2025-12-28 00:17:22.446502 | controller | ok
2025-12-28 00:17:22.475934 | 
2025-12-28 00:17:22.476139 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-28 00:17:22.690896 | controller | ok
2025-12-28 00:17:22.699653 | 
2025-12-28 00:17:22.699843 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-28 00:17:23.241050 | controller | skipping: Conditional result was False
2025-12-28 00:17:23.279802 | 
2025-12-28 00:17:23.279913 | PLAY RECAP
2025-12-28 00:17:23.279957 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-28 00:17:23.279978 | 
2025-12-28 00:17:23.451662 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-28 00:17:23.453506 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-28 00:17:24.090452 | 
2025-12-28 00:17:24.090605 | PLAY [controller]
2025-12-28 00:17:24.111205 | 
2025-12-28 00:17:24.111338 | TASK [Create the /root directory]
2025-12-28 00:17:24.487621 | controller | ok
2025-12-28 00:17:24.507677 | 
2025-12-28 00:17:24.507934 | TASK [Install glibc-langpack-en]
2025-12-28 00:17:28.658230 | controller | ok: Nothing to do
2025-12-28 00:17:28.666109 | 
2025-12-28 00:17:28.666207 | TASK [Ensure controller directory exists]
2025-12-28 00:17:28.884449 | controller | changed
2025-12-28 00:17:28.892543 | 
2025-12-28 00:17:28.892645 | TASK [Install container runtime]
2025-12-28 00:17:28.965689 | controller | ok
2025-12-28 00:17:29.009519 | 
2025-12-28 00:17:29.009662 | LOOP [ensure-podman : Find distribution installation]
2025-12-28 00:17:29.035277 | controller | ok: "/var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-28 00:17:29.052616 | controller | included: /var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-28 00:17:29.059584 | 
2025-12-28 00:17:29.059677 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-28 00:18:33.684914 | controller | changed
2025-12-28 00:18:33.701976 | 
2025-12-28 00:18:33.702378 | TASK [ensure-podman : Fetch podman version]
2025-12-28 00:18:34.282222 | controller | Client:       Podman Engine
2025-12-28 00:18:34.312006 | controller | Version:      4.6.2
2025-12-28 00:18:34.312049 | controller | API Version:  4.6.2
2025-12-28 00:18:34.312063 | controller | Go Version:   go1.19.12
2025-12-28 00:18:34.312090 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-28 00:18:34.312103 | controller | OS/Arch:      linux/amd64
2025-12-28 00:18:34.755996 | controller | ok: Runtime: 0:00:00.188977
2025-12-28 00:18:34.764898 | 
2025-12-28 00:18:34.764996 | TASK [ensure-podman : Print podman version installed]
2025-12-28 00:18:34.798135 | Podman version: Client:       Podman Engine
2025-12-28 00:18:34.798510 | Version:      4.6.2
2025-12-28 00:18:34.798562 | API Version:  4.6.2
2025-12-28 00:18:34.798592 | Go Version:   go1.19.12
2025-12-28 00:18:34.798618 | Built:        Mon Aug 28 19:38:31 2023
2025-12-28 00:18:34.798646 | OS/Arch:      linux/amd64
2025-12-28 00:18:34.806716 | 
2025-12-28 00:18:34.806805 | TASK [ensure-podman : Validate podman engine]
2025-12-28 00:18:35.347700 | controller | skipping: Conditional result was False
2025-12-28 00:18:35.362746 | 
2025-12-28 00:18:35.362913 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-28 00:18:35.381423 | controller | skipping: Conditional result was False
2025-12-28 00:18:35.407134 | 
2025-12-28 00:18:35.407272 | TASK [Ensure python3.8 is present]
2025-12-28 00:18:35.432559 | controller | skipping: Conditional result was False
2025-12-28 00:18:35.439539 | 
2025-12-28 00:18:35.439625 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-28 00:18:35.460474 | controller | ok
2025-12-28 00:18:35.482826 | 
2025-12-28 00:18:35.482931 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-28 00:18:36.882794 | controller | ok: Nothing to do
2025-12-28 00:18:36.894417 | 
2025-12-28 00:18:36.894590 | TASK [our-ensure-python : Also install python3-devel]
2025-12-28 00:18:47.553049 | controller | changed
2025-12-28 00:18:47.568926 | 
2025-12-28 00:18:47.569182 | TASK [Run ensure-virtualenv role]
2025-12-28 00:18:47.598847 | controller | ok
2025-12-28 00:18:47.639159 | 
2025-12-28 00:18:47.639327 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-28 00:18:47.938590 | controller | /usr/bin/virtualenv
2025-12-28 00:18:48.245475 | controller | ok: Runtime: 0:00:00.005345
2025-12-28 00:18:48.263148 | 
2025-12-28 00:18:48.263338 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-28 00:18:48.296862 | controller | skipping: Conditional result was False
2025-12-28 00:18:48.297341 | controller | ok: All items complete
2025-12-28 00:18:48.297401 | 
2025-12-28 00:18:48.319305 | 
2025-12-28 00:18:48.319485 | TASK [Find the full path of the Python interpreter]
2025-12-28 00:18:48.561083 | controller | /usr/bin/python3
2025-12-28 00:18:48.865419 | controller | ok
2025-12-28 00:18:48.872701 | 
2025-12-28 00:18:48.872820 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-28 00:18:49.612861 | controller | created virtual environment CPython3.11.0.final.0-64 in 462ms
2025-12-28 00:18:49.634649 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-28 00:18:49.634684 | 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-28 00:18:49.634693 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-28 00:18:49.634707 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-28 00:18:49.913098 | controller | changed
2025-12-28 00:18:49.922764 | 
2025-12-28 00:18:49.922897 | TASK [Set selinux package]
2025-12-28 00:18:49.958436 | controller | ok
2025-12-28 00:18:49.970786 | 
2025-12-28 00:18:49.971007 | TASK [Set selinux package (Fedora)]
2025-12-28 00:18:50.010005 | controller | ok
2025-12-28 00:18:50.017315 | 
2025-12-28 00:18:50.017407 | TASK [Install selinux into virtualenv]
2025-12-28 00:19:27.431105 | controller | Collecting selinux-please-lie-to-me
2025-12-28 00:19:39.696025 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-28 00:19:40.002020 | controller | Collecting setuptools<50.0.0
2025-12-28 00:19:40.006773 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-28 00:19:40.070080 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.2 MB/s eta 0:00:00
2025-12-28 00:19:40.151317 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-28 00:19:40.151529 | controller |   Attempting uninstall: setuptools
2025-12-28 00:19:40.153904 | controller |     Found existing installation: setuptools 62.6.0
2025-12-28 00:19:40.213978 | controller |     Uninstalling setuptools-62.6.0:
2025-12-28 00:19:40.222030 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-28 00:19:40.569132 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-28 00:19:52.083033 | controller |
2025-12-28 00:19:52.177991 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-28 00:19:52.178034 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-28 00:19:52.593242 | controller | ok: Runtime: 0:01:01.955062
2025-12-28 00:19:52.603198 | 
2025-12-28 00:19:52.603390 | TASK [Install pytest-forked into virtualenv]
2025-12-28 00:20:02.267878 | controller | Collecting pytest-forked
2025-12-28 00:20:26.509375 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-28 00:20:26.557901 | controller | Collecting py
2025-12-28 00:20:26.604218 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-28 00:20:26.623005 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.5 MB/s eta 0:00:00
2025-12-28 00:20:26.732840 | controller | Collecting pytest>=3.10
2025-12-28 00:20:26.736981 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-28 00:20:26.754636 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.4 MB/s eta 0:00:00
2025-12-28 00:20:26.793996 | controller | Collecting iniconfig>=1.0.1
2025-12-28 00:20:26.800147 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-28 00:20:26.841029 | controller | Collecting packaging>=22
2025-12-28 00:20:26.846633 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-28 00:20:26.852451 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 17.9 MB/s eta 0:00:00
2025-12-28 00:20:26.881356 | controller | Collecting pluggy<2,>=1.5
2025-12-28 00:20:26.884663 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-28 00:20:26.931663 | controller | Collecting pygments>=2.7.2
2025-12-28 00:20:26.939673 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-28 00:20:26.971493 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 46.6 MB/s eta 0:00:00
2025-12-28 00:20:27.040670 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-28 00:20:28.076629 | 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-28 00:20:28.085238 | controller |
2025-12-28 00:20:28.150406 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-28 00:20:28.150447 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-28 00:20:28.657333 | controller | ok: Runtime: 0:00:35.336299
2025-12-28 00:20:28.673822 | 
2025-12-28 00:20:28.674000 | TASK [Update pip]
2025-12-28 00:20:29.222258 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-28 00:20:41.699405 | controller | Collecting pip
2025-12-28 00:20:53.869963 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-28 00:20:53.933281 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.2 MB/s eta 0:00:00
2025-12-28 00:20:53.998825 | controller | Installing collected packages: pip
2025-12-28 00:20:53.999001 | controller |   Attempting uninstall: pip
2025-12-28 00:20:54.001288 | controller |     Found existing installation: pip 22.2.2
2025-12-28 00:20:54.138447 | controller |     Uninstalling pip-22.2.2:
2025-12-28 00:20:54.153528 | controller |       Successfully uninstalled pip-22.2.2
2025-12-28 00:20:54.945989 | controller | Successfully installed pip-25.3
2025-12-28 00:20:55.244617 | controller | ok: Runtime: 0:00:26.106571
2025-12-28 00:20:55.254132 | 
2025-12-28 00:20:55.254319 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-28 00:20:55.466777 | controller | changed
2025-12-28 00:20:55.478042 | 
2025-12-28 00:20:55.478192 | TASK [Install ansible into virtualenv]
2025-12-28 00:20:56.018241 | controller | Processing ./src/github.com/ansible/ansible
2025-12-28 00:20:56.021513 | controller |   Installing build dependencies: started
2025-12-28 00:21:30.767181 | controller |   Installing build dependencies: finished with status 'done'
2025-12-28 00:21:30.767823 | controller |   Getting requirements to build wheel: started
2025-12-28 00:21:31.615373 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-28 00:21:32.071051 | controller |   Preparing metadata (pyproject.toml): started
2025-12-28 00:21:32.071136 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-28 00:21:32.073668 | 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-28 00:21:32.076200 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-28 00:21:32.597283 | controller | ERROR
2025-12-28 00:21:32.597568 | controller | {
2025-12-28 00:21:32.597608 | controller |   "delta": "0:00:36.411262",
2025-12-28 00:21:32.597635 | controller |   "end": "2025-12-28 00:21:32.152511",
2025-12-28 00:21:32.597658 | controller |   "msg": "non-zero return code",
2025-12-28 00:21:32.597693 | controller |   "rc": 1,
2025-12-28 00:21:32.597716 | controller |   "start": "2025-12-28 00:20:55.741249"
2025-12-28 00:21:32.597738 | controller | }
failure
2025-12-28 00:21:32.600187 | 
2025-12-28 00:21:32.600429 | PLAY RECAP
2025-12-28 00:21:32.600543 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-28 00:21:32.600602 | 
2025-12-28 00:21:32.777894 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-28 00:21:32.779527 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-28 00:21:33.432792 | 
2025-12-28 00:21:33.432944 | PLAY [all]
2025-12-28 00:21:33.456206 | 
2025-12-28 00:21:33.456338 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-28 00:21:33.723311 | controller | changed: non-zero return code
2025-12-28 00:21:33.729322 | 
2025-12-28 00:21:33.729403 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-28 00:21:33.754094 | controller | skipping: Conditional result was False
2025-12-28 00:21:33.760182 | 
2025-12-28 00:21:33.760251 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-28 00:21:33.791281 | 
2025-12-28 00:21:33.791452 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-28 00:21:33.813007 | 
2025-12-28 00:21:33.813224 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-28 00:21:33.837373 | controller | skipping: Conditional result was False
2025-12-28 00:21:33.847263 | 
2025-12-28 00:21:33.847441 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-28 00:21:33.874109 | 
2025-12-28 00:21:33.874346 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-28 00:21:33.890191 | controller | skipping: Conditional result was False
2025-12-28 00:21:33.899893 | 
2025-12-28 00:21:33.900089 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-28 00:21:33.916480 | controller | skipping: Conditional result was False
2025-12-28 00:21:33.923913 | 
2025-12-28 00:21:33.924043 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-28 00:21:33.938607 | controller | skipping: Conditional result was False
2025-12-28 00:21:33.968048 | 
2025-12-28 00:21:33.968167 | PLAY RECAP
2025-12-28 00:21:33.968212 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-28 00:21:33.968233 | 
2025-12-28 00:21:34.095789 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-28 00:21:34.096800 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-28 00:21:34.730369 | 
2025-12-28 00:21:34.730535 | PLAY [all:!appliance*]
2025-12-28 00:21:34.756866 | 
2025-12-28 00:21:34.757128 | TASK [unregister the node]
2025-12-28 00:21:35.292619 | controller | skipping: Conditional result was False
2025-12-28 00:21:35.305947 | 
2025-12-28 00:21:35.306169 | TASK [include_role : fetch-output]
2025-12-28 00:21:35.352145 | controller | ok
2025-12-28 00:21:35.381963 | 
2025-12-28 00:21:35.382111 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-28 00:21:35.458362 | controller | skipping: Conditional result was False
2025-12-28 00:21:35.467372 | 
2025-12-28 00:21:35.467478 | TASK [fetch-output : Set log path for single node]
2025-12-28 00:21:35.521718 | controller | ok
2025-12-28 00:21:35.529146 | 
2025-12-28 00:21:35.529239 | LOOP [fetch-output : Ensure local output dirs]
2025-12-28 00:21:36.008652 | controller -> localhost | ok: "/var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/logs"
2025-12-28 00:21:36.266621 | controller -> localhost | changed: "/var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/artifacts"
2025-12-28 00:21:36.520785 | controller -> localhost | changed: "/var/lib/zuul/builds/9f75db4181b1425cb61fbcdd5246d621/work/docs"
2025-12-28 00:21:36.534196 | 
2025-12-28 00:21:36.534349 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-28 00:21:37.288398 | controller | changed:
2025-12-28 00:21:37.288764 | controller | .d..t...... ./
2025-12-28 00:21:37.288825 | controller | cd+++++++++ controller/
2025-12-28 00:21:37.288892 | controller | changed: All items complete
2025-12-28 00:21:37.288934 | 
2025-12-28 00:21:37.773877 | controller | changed: .d..t...... ./
2025-12-28 00:21:38.298533 | controller | changed: .d..t...... ./
2025-12-28 00:21:38.321452 | 
2025-12-28 00:21:38.321590 | TASK [include_role : fetch-output-openshift]
2025-12-28 00:21:38.336470 | controller | skipping: Conditional result was False
2025-12-28 00:21:38.344468 | 
2025-12-28 00:21:38.344599 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-28 00:21:38.372160 | controller | skipping: Conditional result was False
2025-12-28 00:21:38.383758 | controller | skipping: Conditional result was False
2025-12-28 00:21:38.422153 | 
2025-12-28 00:21:38.422304 | PLAY [localhost]
2025-12-28 00:21:38.439264 | 
2025-12-28 00:21:38.439379 | TASK [Run Zuul manifest role]
2025-12-28 00:21:38.458802 | localhost | ok
2025-12-28 00:21:38.477403 | 
2025-12-28 00:21:38.477545 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-28 00:21:38.861956 | localhost | changed
2025-12-28 00:21:38.873154 | 
2025-12-28 00:21:38.873289 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-28 00:21:38.921826 | localhost | ok
2025-12-28 00:21:38.941505 | 
2025-12-28 00:21:38.941828 | TASK [Set zuul-log-path fact]
2025-12-28 00:21:38.966576 | localhost | ok
2025-12-28 00:21:38.998507 | 
2025-12-28 00:21:38.998651 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-28 00:21:39.041367 | localhost | ok
2025-12-28 00:21:39.053377 | 
2025-12-28 00:21:39.053464 | LOOP [Run upload-logs-swift role]
2025-12-28 00:21:39.089352 | localhost | Output suppressed because no_log was given
2025-12-28 00:21:39.127727 | 
2025-12-28 00:21:39.127878 | TASK [Set zuul-log-path fact]
2025-12-28 00:21:39.164320 | localhost | skipping: Conditional result was False
2025-12-28 00:21:39.170660 | 
2025-12-28 00:21:39.170757 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-28 00:21:39.680268 | localhost -> localhost | ok: Runtime: 0:00:00.011255
2025-12-28 00:21:39.738759 | 
2025-12-28 00:21:39.738919 | TASK [upload-logs-swift : Upload logs to swift]