2025-12-26 00:06:56.779281 | Job console starting...
2025-12-26 00:06:56.789871 | Updating repositories
2025-12-26 00:06:56.896357 | Preparing job workspace
2025-12-26 00:07:03.471821 | Running Ansible setup...
2025-12-26 00:07:08.774507 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:07:09.406077 | 
2025-12-26 00:07:09.406208 | PLAY [localhost]
2025-12-26 00:07:09.415298 | 
2025-12-26 00:07:09.415381 | TASK [Gathering Facts]
2025-12-26 00:07:10.490594 | localhost | ok
2025-12-26 00:07:10.509003 | 
2025-12-26 00:07:10.509173 | TASK [Setup log path fact]
2025-12-26 00:07:10.530411 | localhost | ok
2025-12-26 00:07:10.544848 | 
2025-12-26 00:07:10.544943 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:07:10.585009 | localhost | ok
2025-12-26 00:07:10.596179 | 
2025-12-26 00:07:10.596336 | TASK [emit-job-header : Print job information]
2025-12-26 00:07:10.647469 | # Job Information
2025-12-26 00:07:10.647659 | Ansible Version: 2.15.12
2025-12-26 00:07:10.647702 | Job: ansible-test-sanity-docker-milestone
2025-12-26 00:07:10.647731 | Pipeline: periodic
2025-12-26 00:07:10.647756 | Executor: ze01.softwarefactory-project.io
2025-12-26 00:07:10.647779 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-26 00:07:10.647807 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0c8/ansible/0c82138055364c3e9b27d02352964033/
2025-12-26 00:07:10.647832 | Event ID: 251d181dbd134356bcf2e7a38c8ef353
2025-12-26 00:07:10.652921 | 
2025-12-26 00:07:10.653011 | LOOP [emit-job-header : Print node information]
2025-12-26 00:07:10.763367 | localhost | ok:
2025-12-26 00:07:10.763563 | localhost | # Node Information
2025-12-26 00:07:10.763589 | localhost | Inventory Hostname: controller
2025-12-26 00:07:10.763609 | localhost | Hostname: np0005570829
2025-12-26 00:07:10.763628 | localhost | Username: zuul
2025-12-26 00:07:10.763653 | localhost | Distro: Fedora 37
2025-12-26 00:07:10.763672 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-26 00:07:10.763689 | localhost | Region: ca-ymq-1
2025-12-26 00:07:10.763706 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-26 00:07:10.763722 | localhost | Product Name: OpenStack Nova
2025-12-26 00:07:10.763738 | localhost | Interface IP: 162.253.55.140
2025-12-26 00:07:10.787365 | 
2025-12-26 00:07:10.787909 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-26 00:07:11.180751 | localhost -> localhost | changed
2025-12-26 00:07:11.186345 | 
2025-12-26 00:07:11.186412 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-26 00:07:12.186947 | localhost -> localhost | changed
2025-12-26 00:07:12.207740 | 
2025-12-26 00:07:12.207810 | PLAY [all:!appliance*]
2025-12-26 00:07:12.224047 | 
2025-12-26 00:07:12.224125 | TASK [include_role : start-zuul-console]
2025-12-26 00:07:12.244170 | controller | ok
2025-12-26 00:07:12.259003 | 
2025-12-26 00:07:12.259116 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-26 00:07:12.631251 | controller | ok
2025-12-26 00:07:12.654375 | 
2025-12-26 00:07:12.654507 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-26 00:07:13.494174 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-26 00:07:13.500318 | 
2025-12-26 00:07:13.500380 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-26 00:07:14.031505 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.045519 | 
2025-12-26 00:07:14.045695 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-26 00:07:14.072631 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.081443 | 
2025-12-26 00:07:14.081528 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-26 00:07:14.106869 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.115918 | 
2025-12-26 00:07:14.116009 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-26 00:07:14.140866 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.154425 | 
2025-12-26 00:07:14.154562 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-26 00:07:14.181788 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.195456 | 
2025-12-26 00:07:14.195605 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-26 00:07:14.222108 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.249157 | 
2025-12-26 00:07:14.249308 | TASK [Disable Fedora Modular]
2025-12-26 00:07:14.500385 | controller | changed
2025-12-26 00:07:14.513919 | 
2025-12-26 00:07:14.514092 | TASK [Enable EPEL]
2025-12-26 00:07:14.551352 | controller | skipping: Conditional result was False
2025-12-26 00:07:14.561126 | 
2025-12-26 00:07:14.561233 | TASK [Register the RHEL node]
2025-12-26 00:07:15.113381 | 
2025-12-26 00:07:15.113553 | TASK [Show the subscription-manager status]
2025-12-26 00:07:15.685602 | controller | skipping: Conditional result was False
2025-12-26 00:07:15.699194 | 
2025-12-26 00:07:15.699328 | TASK [Enable EPEL on RHEL]
2025-12-26 00:07:16.256010 | controller | skipping: Conditional result was False
2025-12-26 00:07:16.269574 | 
2025-12-26 00:07:16.269744 | TASK [Install git and tox]
2025-12-26 00:08:43.651736 | controller | changed
2025-12-26 00:08:43.664597 | 
2025-12-26 00:08:43.664705 | TASK [include_role : prepare-workspace]
2025-12-26 00:08:43.697883 | controller | ok
2025-12-26 00:08:43.726255 | 
2025-12-26 00:08:43.726425 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-26 00:08:43.983990 | controller | ok
2025-12-26 00:08:43.997321 | 
2025-12-26 00:08:43.997412 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-26 00:09:03.348354 | controller | Output suppressed because no_log was given
2025-12-26 00:09:03.367541 | 
2025-12-26 00:09:03.367679 | TASK [include_role : prepare-workspace-openshift]
2025-12-26 00:09:03.384155 | controller | skipping: Conditional result was False
2025-12-26 00:09:03.448682 | 
2025-12-26 00:09:03.448762 | PLAY [all:!appliance]
2025-12-26 00:09:03.470677 | 
2025-12-26 00:09:03.470809 | TASK [Run add-build-sshkey role (RSA)]
2025-12-26 00:09:03.504404 | controller | ok
2025-12-26 00:09:03.523169 | 
2025-12-26 00:09:03.523297 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:09:03.794565 | controller -> localhost | ok
2025-12-26 00:09:03.801538 | 
2025-12-26 00:09:03.801618 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:09:03.831691 | controller | ok
2025-12-26 00:09:03.846508 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:09:03.852536 | 
2025-12-26 00:09:03.852599 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:09:04.376303 | controller -> localhost | Generating public/private rsa key pair.
2025-12-26 00:09:04.376634 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_rsa.
2025-12-26 00:09:04.376701 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_rsa.pub.
2025-12-26 00:09:04.376749 | controller -> localhost | The key fingerprint is:
2025-12-26 00:09:04.376795 | controller -> localhost | SHA256:6omCQXX+ap+l8p7FS6VhSO/h3+RIPyoDDjXUcYnoqOg zuul-build-sshkey
2025-12-26 00:09:04.376840 | controller -> localhost | The key's randomart image is:
2025-12-26 00:09:04.376885 | controller -> localhost | +---[RSA 2048]----+
2025-12-26 00:09:04.376931 | controller -> localhost | |        o.o..    |
2025-12-26 00:09:04.376973 | controller -> localhost | |   . . o o..     |
2025-12-26 00:09:04.377095 | controller -> localhost | |  . o +.         |
2025-12-26 00:09:04.377156 | controller -> localhost | | .   o.+o        |
2025-12-26 00:09:04.377200 | controller -> localhost | |. . . o.S= .     |
2025-12-26 00:09:04.377261 | controller -> localhost | |.. . . += =      |
2025-12-26 00:09:04.377310 | controller -> localhost | |.o    = .O . .   |
2025-12-26 00:09:04.377353 | controller -> localhost | |.E.  * oBo+ *.   |
2025-12-26 00:09:04.377394 | controller -> localhost | |   .o BB .o+.+.  |
2025-12-26 00:09:04.377440 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:09:04.377525 | controller -> localhost | ok: Runtime: 0:00:00.146786
2025-12-26 00:09:04.391252 | 
2025-12-26 00:09:04.391387 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:09:04.422211 | controller | ok
2025-12-26 00:09:04.445159 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:09:04.457834 | 
2025-12-26 00:09:04.457928 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:09:04.474167 | controller | skipping: Conditional result was False
2025-12-26 00:09:04.483927 | 
2025-12-26 00:09:04.484068 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:09:04.919924 | controller | changed
2025-12-26 00:09:04.933441 | 
2025-12-26 00:09:04.933584 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:09:05.162941 | controller | ok
2025-12-26 00:09:05.171511 | 
2025-12-26 00:09:05.171615 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:09:05.840709 | controller | changed
2025-12-26 00:09:05.851180 | 
2025-12-26 00:09:05.851268 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:09:06.509132 | controller | changed
2025-12-26 00:09:06.516607 | 
2025-12-26 00:09:06.516724 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:09:06.542250 | controller | skipping: Conditional result was False
2025-12-26 00:09:06.550011 | 
2025-12-26 00:09:06.550195 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:09:06.931775 | controller -> localhost | changed
2025-12-26 00:09:06.943783 | 
2025-12-26 00:09:06.943883 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:09:07.216521 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_rsa (zuul-build-sshkey)
2025-12-26 00:09:07.216714 | controller -> localhost | ok: Runtime: 0:00:00.012344
2025-12-26 00:09:07.225224 | 
2025-12-26 00:09:07.225325 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:09:07.574294 | controller | ok
2025-12-26 00:09:07.588283 | 
2025-12-26 00:09:07.588403 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:09:07.623239 | controller | skipping: Conditional result was False
2025-12-26 00:09:07.641485 | 
2025-12-26 00:09:07.641618 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-26 00:09:07.666732 | controller | ok
2025-12-26 00:09:07.689144 | 
2025-12-26 00:09:07.689296 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:09:07.948719 | controller -> localhost | ok
2025-12-26 00:09:07.958709 | 
2025-12-26 00:09:07.958813 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:09:07.986192 | controller | ok
2025-12-26 00:09:08.006843 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:09:08.018274 | 
2025-12-26 00:09:08.018446 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:09:08.312799 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-26 00:09:08.313162 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_ecdsa.
2025-12-26 00:09:08.313221 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_ecdsa.pub.
2025-12-26 00:09:08.313277 | controller -> localhost | The key fingerprint is:
2025-12-26 00:09:08.313319 | controller -> localhost | SHA256:GIcrmZ1yLBJpNqvW6xaqAwWxKrXYt6taqLpCVZm9TrM zuul-build-sshkey
2025-12-26 00:09:08.313387 | controller -> localhost | The key's randomart image is:
2025-12-26 00:09:08.313427 | controller -> localhost | +---[ECDSA 521]---+
2025-12-26 00:09:08.313465 | controller -> localhost | |..    +          |
2025-12-26 00:09:08.313502 | controller -> localhost | |.. . + o         |
2025-12-26 00:09:08.313540 | controller -> localhost | |..B . o o        |
2025-12-26 00:09:08.313578 | controller -> localhost | |.*.* = X         |
2025-12-26 00:09:08.313616 | controller -> localhost | |+.* B X S        |
2025-12-26 00:09:08.313655 | controller -> localhost | |o+.+ * E         |
2025-12-26 00:09:08.313692 | controller -> localhost | |=.o.o            |
2025-12-26 00:09:08.313753 | controller -> localhost | |=o ...           |
2025-12-26 00:09:08.313795 | controller -> localhost | |X+++.            |
2025-12-26 00:09:08.313835 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:09:08.313923 | controller -> localhost | ok: Runtime: 0:00:00.014119
2025-12-26 00:09:08.329973 | 
2025-12-26 00:09:08.330164 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:09:08.354881 | controller | ok
2025-12-26 00:09:08.362996 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:09:08.372893 | 
2025-12-26 00:09:08.372986 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:09:08.397035 | controller | skipping: Conditional result was False
2025-12-26 00:09:08.403831 | 
2025-12-26 00:09:08.403908 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:09:08.678254 | controller | changed
2025-12-26 00:09:08.686281 | 
2025-12-26 00:09:08.686394 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:09:08.959896 | controller | ok
2025-12-26 00:09:08.969921 | 
2025-12-26 00:09:08.970105 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:09:09.638293 | controller | changed
2025-12-26 00:09:09.648103 | 
2025-12-26 00:09:09.648238 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:09:10.300543 | controller | changed
2025-12-26 00:09:10.306467 | 
2025-12-26 00:09:10.306530 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:09:10.331163 | controller | skipping: Conditional result was False
2025-12-26 00:09:10.338930 | 
2025-12-26 00:09:10.339038 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:09:10.608558 | controller -> localhost | changed
2025-12-26 00:09:10.654651 | 
2025-12-26 00:09:10.654770 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:09:10.932859 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/0c82138055364c3e9b27d02352964033_id_ecdsa (zuul-build-sshkey)
2025-12-26 00:09:10.933148 | controller -> localhost | ok: Runtime: 0:00:00.008189
2025-12-26 00:09:10.942793 | 
2025-12-26 00:09:10.942941 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:09:11.151086 | controller | ok
2025-12-26 00:09:11.160278 | 
2025-12-26 00:09:11.160385 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:09:11.185777 | controller | skipping: Conditional result was False
2025-12-26 00:09:11.205718 | 
2025-12-26 00:09:11.205856 | TASK [include_role : remove-zuul-sshkey]
2025-12-26 00:09:11.231291 | controller | skipping: Conditional result was False
2025-12-26 00:09:11.238417 | 
2025-12-26 00:09:11.238516 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-26 00:09:11.458939 | controller | ok: "logs"
2025-12-26 00:09:11.459382 | controller | ok: All items complete
2025-12-26 00:09:11.459419 | 
2025-12-26 00:09:11.661689 | controller | ok: "artifacts"
2025-12-26 00:09:11.857756 | controller | ok: "docs"
2025-12-26 00:09:11.875565 | 
2025-12-26 00:09:11.875689 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-26 00:09:12.108809 | controller | changed: "logs"
2025-12-26 00:09:12.311766 | controller | changed: "artifacts"
2025-12-26 00:09:12.503641 | controller | changed: "docs"
2025-12-26 00:09:12.556714 | 
2025-12-26 00:09:12.556827 | PLAY RECAP
2025-12-26 00:09:12.556888 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-26 00:09:12.556968 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-26 00:09:12.557038 | 
2025-12-26 00:09:12.699567 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:09:12.700494 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:09:13.276530 | 
2025-12-26 00:09:13.276660 | PLAY [all]
2025-12-26 00:09:13.301549 | 
2025-12-26 00:09:13.301673 | TASK [Install binary dependencies]
2025-12-26 00:09:13.352879 | controller | ok
2025-12-26 00:09:13.376488 | 
2025-12-26 00:09:13.376666 | TASK [bindep : Include find tasks]
2025-12-26 00:09:13.408787 | controller | ok
2025-12-26 00:09:13.417757 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-26 00:09:13.424938 | 
2025-12-26 00:09:13.425045 | TASK [bindep : Look for bindep.txt]
2025-12-26 00:09:13.782187 | controller | ok
2025-12-26 00:09:13.788089 | 
2025-12-26 00:09:13.788173 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:09:13.812723 | controller | skipping: Conditional result was False
2025-12-26 00:09:13.822116 | 
2025-12-26 00:09:13.822481 | TASK [bindep : Look for other-requirements.txt]
2025-12-26 00:09:14.039442 | controller | ok
2025-12-26 00:09:14.048488 | 
2025-12-26 00:09:14.048615 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:09:14.084245 | controller | skipping: Conditional result was False
2025-12-26 00:09:14.091799 | 
2025-12-26 00:09:14.091906 | TASK [bindep : Look for bindep fallback file]
2025-12-26 00:09:14.118794 | controller | skipping: Conditional result was False
2025-12-26 00:09:14.128745 | 
2025-12-26 00:09:14.128866 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:09:14.153780 | controller | skipping: Conditional result was False
2025-12-26 00:09:14.160952 | 
2025-12-26 00:09:14.161093 | TASK [bindep : Include bindep tasks]
2025-12-26 00:09:14.185502 | controller | skipping: Conditional result was False
2025-12-26 00:09:14.192782 | 
2025-12-26 00:09:14.192876 | TASK [bindep : Include install tasks]
2025-12-26 00:09:14.217080 | controller | skipping: Conditional result was False
2025-12-26 00:09:14.227643 | 
2025-12-26 00:09:14.227783 | LOOP [bindep : Include package tasks]
2025-12-26 00:09:14.292914 | 
2025-12-26 00:09:14.293173 | TASK [Run test-setup role]
2025-12-26 00:09:14.320984 | controller | ok
2025-12-26 00:09:14.349861 | 
2025-12-26 00:09:14.350007 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-26 00:09:14.560762 | controller | ok
2025-12-26 00:09:14.574808 | 
2025-12-26 00:09:14.574965 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-26 00:09:15.125480 | controller | skipping: Conditional result was False
2025-12-26 00:09:15.180824 | 
2025-12-26 00:09:15.180934 | PLAY RECAP
2025-12-26 00:09:15.180987 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:09:15.181039 | 
2025-12-26 00:09:15.293851 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:09:15.295644 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:09:15.904275 | 
2025-12-26 00:09:15.904419 | PLAY [controller]
2025-12-26 00:09:15.926434 | 
2025-12-26 00:09:15.926582 | TASK [Create the /root directory]
2025-12-26 00:09:16.313319 | controller | ok
2025-12-26 00:09:16.327384 | 
2025-12-26 00:09:16.327601 | TASK [Install glibc-langpack-en]
2025-12-26 00:09:20.347668 | controller | ok: Nothing to do
2025-12-26 00:09:20.367872 | 
2025-12-26 00:09:20.368115 | TASK [Ensure controller directory exists]
2025-12-26 00:09:20.581465 | controller | changed
2025-12-26 00:09:20.595673 | 
2025-12-26 00:09:20.595831 | TASK [Install container runtime]
2025-12-26 00:09:20.651133 | controller | ok
2025-12-26 00:09:20.699669 | 
2025-12-26 00:09:20.699814 | LOOP [ensure-podman : Find distribution installation]
2025-12-26 00:09:20.731343 | controller | ok: "/var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-26 00:09:20.747458 | controller | included: /var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-26 00:09:20.757428 | 
2025-12-26 00:09:20.757546 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-26 00:10:29.765201 | controller | changed
2025-12-26 00:10:29.779450 | 
2025-12-26 00:10:29.779591 | TASK [ensure-podman : Fetch podman version]
2025-12-26 00:10:30.317445 | controller | Client:       Podman Engine
2025-12-26 00:10:30.346275 | controller | Version:      4.6.2
2025-12-26 00:10:30.346314 | controller | API Version:  4.6.2
2025-12-26 00:10:30.346322 | controller | Go Version:   go1.19.12
2025-12-26 00:10:30.346340 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:10:30.346348 | controller | OS/Arch:      linux/amd64
2025-12-26 00:10:30.817572 | controller | ok: Runtime: 0:00:00.203844
2025-12-26 00:10:30.832753 | 
2025-12-26 00:10:30.832914 | TASK [ensure-podman : Print podman version installed]
2025-12-26 00:10:30.863610 | Podman version: Client:       Podman Engine
2025-12-26 00:10:30.863851 | Version:      4.6.2
2025-12-26 00:10:30.863911 | API Version:  4.6.2
2025-12-26 00:10:30.863955 | Go Version:   go1.19.12
2025-12-26 00:10:30.863996 | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:10:30.864088 | OS/Arch:      linux/amd64
2025-12-26 00:10:30.876189 | 
2025-12-26 00:10:30.876321 | TASK [ensure-podman : Validate podman engine]
2025-12-26 00:10:31.423781 | controller | skipping: Conditional result was False
2025-12-26 00:10:31.430831 | 
2025-12-26 00:10:31.430920 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-26 00:10:31.455528 | controller | skipping: Conditional result was False
2025-12-26 00:10:31.467145 | 
2025-12-26 00:10:31.467257 | TASK [Ensure python3.8 is present]
2025-12-26 00:10:31.512366 | controller | skipping: Conditional result was False
2025-12-26 00:10:31.519073 | 
2025-12-26 00:10:31.519160 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-26 00:10:31.541145 | controller | ok
2025-12-26 00:10:31.566688 | 
2025-12-26 00:10:31.566781 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-26 00:10:33.126671 | controller | ok: Nothing to do
2025-12-26 00:10:33.133679 | 
2025-12-26 00:10:33.133746 | TASK [our-ensure-python : Also install python3-devel]
2025-12-26 00:10:42.046517 | controller | changed
2025-12-26 00:10:42.072766 | 
2025-12-26 00:10:42.072965 | TASK [Run ensure-virtualenv role]
2025-12-26 00:10:42.096946 | controller | ok
2025-12-26 00:10:42.129869 | 
2025-12-26 00:10:42.130055 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-26 00:10:42.347062 | controller | /usr/bin/virtualenv
2025-12-26 00:10:42.665029 | controller | ok: Runtime: 0:00:00.005560
2025-12-26 00:10:42.673503 | 
2025-12-26 00:10:42.673646 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-26 00:10:42.694937 | controller | skipping: Conditional result was False
2025-12-26 00:10:42.695349 | controller | ok: All items complete
2025-12-26 00:10:42.695390 | 
2025-12-26 00:10:42.716358 | 
2025-12-26 00:10:42.716478 | TASK [Find the full path of the Python interpreter]
2025-12-26 00:10:42.972471 | controller | /usr/bin/python3
2025-12-26 00:10:43.284899 | controller | ok
2025-12-26 00:10:43.297467 | 
2025-12-26 00:10:43.297605 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-26 00:10:44.143423 | controller | created virtual environment CPython3.11.0.final.0-64 in 490ms
2025-12-26 00:10:44.169935 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-26 00:10:44.169975 | 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-26 00:10:44.169984 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-26 00:10:44.169999 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-26 00:10:44.342460 | controller | changed
2025-12-26 00:10:44.352128 | 
2025-12-26 00:10:44.352258 | TASK [Set selinux package]
2025-12-26 00:10:44.374710 | controller | ok
2025-12-26 00:10:44.380304 | 
2025-12-26 00:10:44.380402 | TASK [Set selinux package (Fedora)]
2025-12-26 00:10:44.412738 | controller | ok
2025-12-26 00:10:44.418269 | 
2025-12-26 00:10:44.418365 | TASK [Install selinux into virtualenv]
2025-12-26 00:11:21.800994 | controller | Collecting selinux-please-lie-to-me
2025-12-26 00:11:34.063636 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-26 00:11:34.370551 | controller | Collecting setuptools<50.0.0
2025-12-26 00:11:34.375937 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-26 00:11:34.411296 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.3 MB/s eta 0:00:00
2025-12-26 00:11:34.493343 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-26 00:11:34.493518 | controller |   Attempting uninstall: setuptools
2025-12-26 00:11:34.495891 | controller |     Found existing installation: setuptools 62.6.0
2025-12-26 00:11:34.556417 | controller |     Uninstalling setuptools-62.6.0:
2025-12-26 00:11:34.564254 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-26 00:11:34.913245 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-26 00:11:46.438473 | controller |
2025-12-26 00:11:46.520158 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:11:46.520202 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:11:46.978647 | controller | ok: Runtime: 0:01:01.898528
2025-12-26 00:11:46.984998 | 
2025-12-26 00:11:46.985138 | TASK [Install pytest-forked into virtualenv]
2025-12-26 00:11:59.828411 | controller | Collecting pytest-forked
2025-12-26 00:12:12.077629 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-26 00:12:12.132548 | controller | Collecting py
2025-12-26 00:12:12.137641 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-26 00:12:12.162426 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.2 MB/s eta 0:00:00
2025-12-26 00:12:12.270295 | controller | Collecting pytest>=3.10
2025-12-26 00:12:12.276024 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-26 00:12:12.295661 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 23.3 MB/s eta 0:00:00
2025-12-26 00:12:12.335946 | controller | Collecting iniconfig>=1.0.1
2025-12-26 00:12:12.341714 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-26 00:12:12.390112 | controller | Collecting packaging>=22
2025-12-26 00:12:12.394204 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-26 00:12:12.402669 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.4 MB/s eta 0:00:00
2025-12-26 00:12:12.432351 | controller | Collecting pluggy<2,>=1.5
2025-12-26 00:12:12.435383 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-26 00:12:12.489274 | controller | Collecting pygments>=2.7.2
2025-12-26 00:12:12.492937 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-26 00:12:12.512304 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 80.6 MB/s eta 0:00:00
2025-12-26 00:12:12.583007 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-26 00:12:13.724438 | 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-26 00:12:13.735084 | controller |
2025-12-26 00:12:13.819074 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:12:13.819115 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:12:14.033437 | controller | ok: Runtime: 0:00:26.639127
2025-12-26 00:12:14.045691 | 
2025-12-26 00:12:14.045843 | TASK [Update pip]
2025-12-26 00:12:14.624423 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-26 00:12:48.333551 | controller | Collecting pip
2025-12-26 00:13:12.497575 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-26 00:13:12.562397 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.2 MB/s eta 0:00:00
2025-12-26 00:13:12.627409 | controller | Installing collected packages: pip
2025-12-26 00:13:12.627646 | controller |   Attempting uninstall: pip
2025-12-26 00:13:12.629729 | controller |     Found existing installation: pip 22.2.2
2025-12-26 00:13:12.775402 | controller |     Uninstalling pip-22.2.2:
2025-12-26 00:13:12.792352 | controller |       Successfully uninstalled pip-22.2.2
2025-12-26 00:13:13.629444 | controller | Successfully installed pip-25.3
2025-12-26 00:13:14.127259 | controller | ok: Runtime: 0:00:59.399252
2025-12-26 00:13:14.144525 | 
2025-12-26 00:13:14.144706 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-26 00:13:14.400049 | controller | changed
2025-12-26 00:13:14.407647 | 
2025-12-26 00:13:14.407740 | TASK [Install ansible into virtualenv]
2025-12-26 00:13:14.977938 | controller | Processing ./src/github.com/ansible/ansible
2025-12-26 00:13:14.981463 | controller |   Installing build dependencies: started
2025-12-26 00:13:37.465417 | controller |   Installing build dependencies: finished with status 'done'
2025-12-26 00:13:37.466702 | controller |   Getting requirements to build wheel: started
2025-12-26 00:13:38.203746 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-26 00:13:38.205068 | controller |   Preparing metadata (pyproject.toml): started
2025-12-26 00:13:38.666973 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-26 00:13:38.673035 | 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-26 00:13:38.678474 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-26 00:13:38.989682 | controller | ERROR
2025-12-26 00:13:38.989914 | controller | {
2025-12-26 00:13:38.989954 | controller |   "delta": "0:00:24.069359",
2025-12-26 00:13:38.990087 | controller |   "end": "2025-12-26 00:13:38.740770",
2025-12-26 00:13:38.990160 | controller |   "msg": "non-zero return code",
2025-12-26 00:13:38.990198 | controller |   "rc": 1,
2025-12-26 00:13:38.990222 | controller |   "start": "2025-12-26 00:13:14.671411"
2025-12-26 00:13:38.990242 | controller | }
failure
2025-12-26 00:13:38.993894 | 
2025-12-26 00:13:38.993972 | PLAY RECAP
2025-12-26 00:13:38.994052 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-26 00:13:38.994087 | 
2025-12-26 00:13:39.118326 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:13:39.120250 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:13:39.779363 | 
2025-12-26 00:13:39.779489 | PLAY [all]
2025-12-26 00:13:39.802678 | 
2025-12-26 00:13:39.802795 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-26 00:13:40.094745 | controller | changed: non-zero return code
2025-12-26 00:13:40.103608 | 
2025-12-26 00:13:40.103775 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-26 00:13:40.131579 | controller | skipping: Conditional result was False
2025-12-26 00:13:40.141712 | 
2025-12-26 00:13:40.141871 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-26 00:13:40.180949 | 
2025-12-26 00:13:40.181558 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-26 00:13:40.216478 | 
2025-12-26 00:13:40.216702 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-26 00:13:40.244177 | controller | skipping: Conditional result was False
2025-12-26 00:13:40.252037 | 
2025-12-26 00:13:40.252125 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-26 00:13:40.290469 | 
2025-12-26 00:13:40.290812 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-26 00:13:40.317379 | controller | skipping: Conditional result was False
2025-12-26 00:13:40.328244 | 
2025-12-26 00:13:40.328357 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-26 00:13:40.354207 | controller | skipping: Conditional result was False
2025-12-26 00:13:40.364868 | 
2025-12-26 00:13:40.364971 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-26 00:13:40.380893 | controller | skipping: Conditional result was False
2025-12-26 00:13:40.420740 | 
2025-12-26 00:13:40.420879 | PLAY RECAP
2025-12-26 00:13:40.420940 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:13:40.420968 | 
2025-12-26 00:13:40.548098 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:13:40.549347 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-26 00:13:41.169299 | 
2025-12-26 00:13:41.169422 | PLAY [all:!appliance*]
2025-12-26 00:13:41.208900 | 
2025-12-26 00:13:41.209068 | TASK [unregister the node]
2025-12-26 00:13:41.745071 | controller | skipping: Conditional result was False
2025-12-26 00:13:41.751358 | 
2025-12-26 00:13:41.751455 | TASK [include_role : fetch-output]
2025-12-26 00:13:41.792054 | controller | ok
2025-12-26 00:13:41.814769 | 
2025-12-26 00:13:41.814892 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-26 00:13:41.900112 | controller | skipping: Conditional result was False
2025-12-26 00:13:41.907385 | 
2025-12-26 00:13:41.907471 | TASK [fetch-output : Set log path for single node]
2025-12-26 00:13:41.969124 | controller | ok
2025-12-26 00:13:41.976798 | 
2025-12-26 00:13:41.976903 | LOOP [fetch-output : Ensure local output dirs]
2025-12-26 00:13:42.406429 | controller -> localhost | ok: "/var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/logs"
2025-12-26 00:13:42.652697 | controller -> localhost | changed: "/var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/artifacts"
2025-12-26 00:13:42.930210 | controller -> localhost | changed: "/var/lib/zuul/builds/0c82138055364c3e9b27d02352964033/work/docs"
2025-12-26 00:13:42.945869 | 
2025-12-26 00:13:42.946086 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-26 00:13:43.707208 | controller | changed:
2025-12-26 00:13:43.707464 | controller | .d..t...... ./
2025-12-26 00:13:43.707519 | controller | cd+++++++++ controller/
2025-12-26 00:13:43.707578 | controller | changed: All items complete
2025-12-26 00:13:43.707620 | 
2025-12-26 00:13:44.179997 | controller | changed: .d..t...... ./
2025-12-26 00:13:44.658966 | controller | changed: .d..t...... ./
2025-12-26 00:13:44.697904 | 
2025-12-26 00:13:44.698141 | TASK [include_role : fetch-output-openshift]
2025-12-26 00:13:44.716970 | controller | skipping: Conditional result was False
2025-12-26 00:13:44.726993 | 
2025-12-26 00:13:44.727124 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-26 00:13:44.770385 | controller | skipping: Conditional result was False
2025-12-26 00:13:44.783182 | controller | skipping: Conditional result was False
2025-12-26 00:13:44.832877 | 
2025-12-26 00:13:44.833089 | PLAY [localhost]
2025-12-26 00:13:44.852472 | 
2025-12-26 00:13:44.852605 | TASK [Run Zuul manifest role]
2025-12-26 00:13:44.884799 | localhost | ok
2025-12-26 00:13:44.899551 | 
2025-12-26 00:13:44.899631 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-26 00:13:45.328385 | localhost | changed
2025-12-26 00:13:45.333601 | 
2025-12-26 00:13:45.333667 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-26 00:13:45.375030 | localhost | ok
2025-12-26 00:13:45.384789 | 
2025-12-26 00:13:45.384943 | TASK [Set zuul-log-path fact]
2025-12-26 00:13:45.404782 | localhost | ok
2025-12-26 00:13:45.420046 | 
2025-12-26 00:13:45.420155 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:13:45.452814 | localhost | ok
2025-12-26 00:13:45.464451 | 
2025-12-26 00:13:45.464564 | LOOP [Run upload-logs-swift role]
2025-12-26 00:13:45.511526 | localhost | Output suppressed because no_log was given
2025-12-26 00:13:45.539990 | 
2025-12-26 00:13:45.540189 | TASK [Set zuul-log-path fact]
2025-12-26 00:13:45.575965 | localhost | skipping: Conditional result was False
2025-12-26 00:13:45.588266 | 
2025-12-26 00:13:45.588434 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-26 00:13:46.055189 | localhost -> localhost | ok: Runtime: 0:00:00.008485
2025-12-26 00:13:46.134079 | 
2025-12-26 00:13:46.134231 | TASK [upload-logs-swift : Upload logs to swift]