2025-12-18 00:07:31.112648 | Job console starting...
2025-12-18 00:07:31.125790 | Updating repositories
2025-12-18 00:07:31.256490 | Preparing job workspace
2025-12-18 00:07:37.472787 | Running Ansible setup...
2025-12-18 00:07:45.938773 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-18 00:07:46.616710 | 
2025-12-18 00:07:46.616846 | PLAY [localhost]
2025-12-18 00:07:46.626461 | 
2025-12-18 00:07:46.626604 | TASK [Gathering Facts]
2025-12-18 00:07:47.641883 | localhost | ok
2025-12-18 00:07:47.657882 | 
2025-12-18 00:07:47.658021 | TASK [Setup log path fact]
2025-12-18 00:07:47.692413 | localhost | ok
2025-12-18 00:07:47.714545 | 
2025-12-18 00:07:47.714716 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-18 00:07:47.755219 | localhost | ok
2025-12-18 00:07:47.767273 | 
2025-12-18 00:07:47.767439 | TASK [emit-job-header : Print job information]
2025-12-18 00:07:47.809309 | # Job Information
2025-12-18 00:07:47.809501 | Ansible Version: 2.15.12
2025-12-18 00:07:47.809560 | Job: ansible-test-sanity-docker-devel
2025-12-18 00:07:47.809608 | Pipeline: periodic
2025-12-18 00:07:47.809650 | Executor: ze04.softwarefactory-project.io
2025-12-18 00:07:47.809746 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-18 00:07:47.809788 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/068/ansible/0686fc40d527479abf6e8fa87bed7cad/
2025-12-18 00:07:47.809818 | Event ID: 95f00f3203bf47de8d788a25b598cc45
2025-12-18 00:07:47.815606 | 
2025-12-18 00:07:47.815743 | LOOP [emit-job-header : Print node information]
2025-12-18 00:07:47.933322 | localhost | ok:
2025-12-18 00:07:47.933768 | localhost | # Node Information
2025-12-18 00:07:47.933829 | localhost | Inventory Hostname: controller
2025-12-18 00:07:47.933866 | localhost | Hostname: np0005564916
2025-12-18 00:07:47.933900 | localhost | Username: zuul
2025-12-18 00:07:47.933945 | localhost | Distro: Fedora 37
2025-12-18 00:07:47.933982 | localhost | Provider: ansible-vexxhost-ams1
2025-12-18 00:07:47.934015 | localhost | Region: ams1
2025-12-18 00:07:47.934046 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-18 00:07:47.934076 | localhost | Product Name: OpenStack Nova
2025-12-18 00:07:47.934105 | localhost | Interface IP: 38.129.16.199
2025-12-18 00:07:47.958432 | 
2025-12-18 00:07:47.958606 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-18 00:07:48.420327 | localhost -> localhost | changed
2025-12-18 00:07:48.425899 | 
2025-12-18 00:07:48.425992 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-18 00:07:49.444766 | localhost -> localhost | changed
2025-12-18 00:07:49.465929 | 
2025-12-18 00:07:49.466186 | PLAY [all:!appliance*]
2025-12-18 00:07:49.485147 | 
2025-12-18 00:07:49.485276 | TASK [include_role : start-zuul-console]
2025-12-18 00:07:49.505493 | controller | ok
2025-12-18 00:07:49.520785 | 
2025-12-18 00:07:49.520866 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-18 00:07:50.641736 | controller | ok
2025-12-18 00:07:50.665803 | 
2025-12-18 00:07:50.666044 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-18 00:07:52.833070 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-18 00:07:52.843933 | 
2025-12-18 00:07:52.844072 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-18 00:07:53.215646 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.231138 | 
2025-12-18 00:07:53.231346 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-18 00:07:53.262366 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.271175 | 
2025-12-18 00:07:53.271294 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-18 00:07:53.295925 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.308882 | 
2025-12-18 00:07:53.309012 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-18 00:07:53.333569 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.341980 | 
2025-12-18 00:07:53.342081 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-18 00:07:53.366669 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.375855 | 
2025-12-18 00:07:53.375954 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-18 00:07:53.401297 | controller | skipping: Conditional result was False
2025-12-18 00:07:53.414522 | 
2025-12-18 00:07:53.414649 | TASK [Disable Fedora Modular]
2025-12-18 00:07:54.593628 | controller | changed
2025-12-18 00:07:54.601671 | 
2025-12-18 00:07:54.601894 | TASK [Enable EPEL]
2025-12-18 00:07:54.629079 | controller | skipping: Conditional result was False
2025-12-18 00:07:54.638392 | 
2025-12-18 00:07:54.638590 | TASK [Register the RHEL node]
2025-12-18 00:07:55.057004 | 
2025-12-18 00:07:55.057372 | TASK [Show the subscription-manager status]
2025-12-18 00:07:55.415228 | controller | skipping: Conditional result was False
2025-12-18 00:07:55.425777 | 
2025-12-18 00:07:55.426192 | TASK [Enable EPEL on RHEL]
2025-12-18 00:07:55.831758 | controller | skipping: Conditional result was False
2025-12-18 00:07:55.838613 | 
2025-12-18 00:07:55.838728 | TASK [Install git and tox]
2025-12-18 00:10:16.255264 | controller | changed
2025-12-18 00:10:16.263042 | 
2025-12-18 00:10:16.263166 | TASK [include_role : prepare-workspace]
2025-12-18 00:10:16.285485 | controller | ok
2025-12-18 00:10:16.316076 | 
2025-12-18 00:10:16.316228 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-18 00:10:17.243345 | controller | ok
2025-12-18 00:10:17.254747 | 
2025-12-18 00:10:17.254907 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-18 00:10:33.449876 | controller | Output suppressed because no_log was given
2025-12-18 00:10:33.475664 | 
2025-12-18 00:10:33.476105 | TASK [include_role : prepare-workspace-openshift]
2025-12-18 00:10:33.494112 | controller | skipping: Conditional result was False
2025-12-18 00:10:33.594305 | 
2025-12-18 00:10:33.594662 | PLAY [all:!appliance]
2025-12-18 00:10:33.620400 | 
2025-12-18 00:10:33.620614 | TASK [Run add-build-sshkey role (RSA)]
2025-12-18 00:10:33.656434 | controller | ok
2025-12-18 00:10:33.678326 | 
2025-12-18 00:10:33.678472 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-18 00:10:33.980804 | controller -> localhost | ok
2025-12-18 00:10:33.989051 | 
2025-12-18 00:10:33.989179 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-18 00:10:34.022836 | controller | ok
2025-12-18 00:10:34.039491 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-18 00:10:34.046136 | 
2025-12-18 00:10:34.046209 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-18 00:10:34.539082 | controller -> localhost | Generating public/private rsa key pair.
2025-12-18 00:10:34.539301 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_rsa.
2025-12-18 00:10:34.539330 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_rsa.pub.
2025-12-18 00:10:34.539350 | controller -> localhost | The key fingerprint is:
2025-12-18 00:10:34.539369 | controller -> localhost | SHA256:SDm8luWH30Mi3Xz8AknrGWQ9wTvlIkONSPnh0GkmFkc zuul-build-sshkey
2025-12-18 00:10:34.539387 | controller -> localhost | The key's randomart image is:
2025-12-18 00:10:34.539422 | controller -> localhost | +---[RSA 2048]----+
2025-12-18 00:10:34.539441 | controller -> localhost | |         .o*E=.  |
2025-12-18 00:10:34.539459 | controller -> localhost | |     . .  *.O.o..|
2025-12-18 00:10:34.539477 | controller -> localhost | |      = .. O+.o+ |
2025-12-18 00:10:34.539494 | controller -> localhost | |     . B o *=++..|
2025-12-18 00:10:34.539511 | controller -> localhost | |      = S + Oooo |
2025-12-18 00:10:34.539537 | controller -> localhost | |     .   + = = . |
2025-12-18 00:10:34.539563 | controller -> localhost | |          . = . .|
2025-12-18 00:10:34.539587 | controller -> localhost | |             . . |
2025-12-18 00:10:34.539606 | controller -> localhost | |                 |
2025-12-18 00:10:34.539626 | controller -> localhost | +----[SHA256]-----+
2025-12-18 00:10:34.539691 | controller -> localhost | ok: Runtime: 0:00:00.072999
2025-12-18 00:10:34.553030 | 
2025-12-18 00:10:34.553143 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-18 00:10:34.592943 | controller | ok
2025-12-18 00:10:34.603714 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-18 00:10:34.613453 | 
2025-12-18 00:10:34.613548 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-18 00:10:34.637831 | controller | skipping: Conditional result was False
2025-12-18 00:10:34.644607 | 
2025-12-18 00:10:34.644673 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-18 00:10:35.833493 | controller | changed
2025-12-18 00:10:35.846906 | 
2025-12-18 00:10:35.847037 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-18 00:10:36.539617 | controller | ok
2025-12-18 00:10:36.553036 | 
2025-12-18 00:10:36.554814 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-18 00:10:39.629595 | controller | changed
2025-12-18 00:10:39.636264 | 
2025-12-18 00:10:39.636385 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-18 00:10:42.701116 | controller | changed
2025-12-18 00:10:42.708158 | 
2025-12-18 00:10:42.708248 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-18 00:10:42.724484 | controller | skipping: Conditional result was False
2025-12-18 00:10:42.735349 | 
2025-12-18 00:10:42.735516 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-18 00:10:43.120262 | controller -> localhost | changed
2025-12-18 00:10:43.137295 | 
2025-12-18 00:10:43.137434 | TASK [add-build-sshkey : Add back temp key]
2025-12-18 00:10:43.461211 | controller -> localhost | Identity added: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_rsa (zuul-build-sshkey)
2025-12-18 00:10:43.461482 | controller -> localhost | ok: Runtime: 0:00:00.014079
2025-12-18 00:10:43.471887 | 
2025-12-18 00:10:43.471977 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-18 00:10:44.454573 | controller | ok
2025-12-18 00:10:44.467985 | 
2025-12-18 00:10:44.468234 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-18 00:10:44.499098 | controller | skipping: Conditional result was False
2025-12-18 00:10:44.513869 | 
2025-12-18 00:10:44.514004 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-18 00:10:44.547544 | controller | ok
2025-12-18 00:10:44.567534 | 
2025-12-18 00:10:44.567659 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-18 00:10:44.829785 | controller -> localhost | ok
2025-12-18 00:10:44.839460 | 
2025-12-18 00:10:44.839582 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-18 00:10:44.871061 | controller | ok
2025-12-18 00:10:44.883715 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-18 00:10:44.897226 | 
2025-12-18 00:10:44.898198 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-18 00:10:45.270664 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-18 00:10:45.270933 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_ecdsa.
2025-12-18 00:10:45.270967 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_ecdsa.pub.
2025-12-18 00:10:45.271001 | controller -> localhost | The key fingerprint is:
2025-12-18 00:10:45.271026 | controller -> localhost | SHA256:vJq1WpBysnTg6Z0JQso6yeliGnsRGDfqTghkfexAJbw zuul-build-sshkey
2025-12-18 00:10:45.271049 | controller -> localhost | The key's randomart image is:
2025-12-18 00:10:45.271071 | controller -> localhost | +---[ECDSA 521]---+
2025-12-18 00:10:45.271093 | controller -> localhost | |  +oo.           |
2025-12-18 00:10:45.271115 | controller -> localhost | |.oo+.o           |
2025-12-18 00:10:45.271136 | controller -> localhost | |o=..*            |
2025-12-18 00:10:45.271157 | controller -> localhost | |=o.E + o         |
2025-12-18 00:10:45.271178 | controller -> localhost | |=...B = S        |
2025-12-18 00:10:45.271199 | controller -> localhost | |++o+ O + .       |
2025-12-18 00:10:45.271220 | controller -> localhost | |Bo .o + +        |
2025-12-18 00:10:45.271241 | controller -> localhost | |o*.    = .       |
2025-12-18 00:10:45.271262 | controller -> localhost | |*o    +..        |
2025-12-18 00:10:45.271282 | controller -> localhost | +----[SHA256]-----+
2025-12-18 00:10:45.271349 | controller -> localhost | ok: Runtime: 0:00:00.014259
2025-12-18 00:10:45.281759 | 
2025-12-18 00:10:45.281856 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-18 00:10:45.315077 | controller | ok
2025-12-18 00:10:45.324779 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-18 00:10:45.336757 | 
2025-12-18 00:10:45.336886 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-18 00:10:45.362192 | controller | skipping: Conditional result was False
2025-12-18 00:10:45.371566 | 
2025-12-18 00:10:45.371670 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-18 00:10:46.353808 | controller | changed
2025-12-18 00:10:46.360701 | 
2025-12-18 00:10:46.360779 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-18 00:10:47.151937 | controller | ok
2025-12-18 00:10:47.161352 | 
2025-12-18 00:10:47.161483 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-18 00:10:50.214271 | controller | changed
2025-12-18 00:10:50.221974 | 
2025-12-18 00:10:50.222102 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-18 00:10:53.235813 | controller | changed
2025-12-18 00:10:53.243284 | 
2025-12-18 00:10:53.243387 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-18 00:10:53.268911 | controller | skipping: Conditional result was False
2025-12-18 00:10:53.276835 | 
2025-12-18 00:10:53.276928 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-18 00:10:53.569669 | controller -> localhost | changed
2025-12-18 00:10:53.595662 | 
2025-12-18 00:10:53.595830 | TASK [add-build-sshkey : Add back temp key]
2025-12-18 00:10:53.908813 | controller -> localhost | Identity added: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/0686fc40d527479abf6e8fa87bed7cad_id_ecdsa (zuul-build-sshkey)
2025-12-18 00:10:53.909164 | controller -> localhost | ok: Runtime: 0:00:00.014890
2025-12-18 00:10:53.921867 | 
2025-12-18 00:10:53.921992 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-18 00:10:54.620185 | controller | ok
2025-12-18 00:10:54.625855 | 
2025-12-18 00:10:54.625925 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-18 00:10:54.680747 | controller | skipping: Conditional result was False
2025-12-18 00:10:54.693120 | 
2025-12-18 00:10:54.693191 | TASK [include_role : remove-zuul-sshkey]
2025-12-18 00:10:54.718018 | controller | skipping: Conditional result was False
2025-12-18 00:10:54.724611 | 
2025-12-18 00:10:54.724713 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-18 00:10:55.377824 | controller | ok: "logs"
2025-12-18 00:10:55.378528 | controller | ok: All items complete
2025-12-18 00:10:55.378579 | 
2025-12-18 00:10:56.015979 | controller | ok: "artifacts"
2025-12-18 00:10:56.667123 | controller | ok: "docs"
2025-12-18 00:10:56.686196 | 
2025-12-18 00:10:56.686346 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-18 00:10:57.381159 | controller | changed: "logs"
2025-12-18 00:10:58.066487 | controller | changed: "artifacts"
2025-12-18 00:10:58.706062 | controller | changed: "docs"
2025-12-18 00:10:58.757196 | 
2025-12-18 00:10:58.757298 | PLAY RECAP
2025-12-18 00:10:58.757341 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-18 00:10:58.757368 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-18 00:10:58.757386 | 
2025-12-18 00:10:58.874459 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-18 00:10:58.875872 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-18 00:10:59.472811 | 
2025-12-18 00:10:59.472939 | PLAY [all]
2025-12-18 00:10:59.502840 | 
2025-12-18 00:10:59.502981 | TASK [Install binary dependencies]
2025-12-18 00:10:59.543608 | controller | ok
2025-12-18 00:10:59.569797 | 
2025-12-18 00:10:59.569931 | TASK [bindep : Include find tasks]
2025-12-18 00:10:59.600206 | controller | ok
2025-12-18 00:10:59.610662 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-18 00:10:59.617254 | 
2025-12-18 00:10:59.617320 | TASK [bindep : Look for bindep.txt]
2025-12-18 00:11:00.563478 | controller | ok
2025-12-18 00:11:00.570061 | 
2025-12-18 00:11:00.570163 | TASK [bindep : Define bindep_file fact]
2025-12-18 00:11:00.583988 | controller | skipping: Conditional result was False
2025-12-18 00:11:00.590659 | 
2025-12-18 00:11:00.590746 | TASK [bindep : Look for other-requirements.txt]
2025-12-18 00:11:01.227484 | controller | ok
2025-12-18 00:11:01.235521 | 
2025-12-18 00:11:01.235620 | TASK [bindep : Define bindep_file fact]
2025-12-18 00:11:01.272892 | controller | skipping: Conditional result was False
2025-12-18 00:11:01.279647 | 
2025-12-18 00:11:01.279764 | TASK [bindep : Look for bindep fallback file]
2025-12-18 00:11:01.315236 | controller | skipping: Conditional result was False
2025-12-18 00:11:01.331600 | 
2025-12-18 00:11:01.333121 | TASK [bindep : Define bindep_file fact]
2025-12-18 00:11:01.358221 | controller | skipping: Conditional result was False
2025-12-18 00:11:01.365642 | 
2025-12-18 00:11:01.365778 | TASK [bindep : Include bindep tasks]
2025-12-18 00:11:01.391144 | controller | skipping: Conditional result was False
2025-12-18 00:11:01.403457 | 
2025-12-18 00:11:01.403596 | TASK [bindep : Include install tasks]
2025-12-18 00:11:01.429948 | controller | skipping: Conditional result was False
2025-12-18 00:11:01.440195 | 
2025-12-18 00:11:01.440299 | LOOP [bindep : Include package tasks]
2025-12-18 00:11:01.507336 | 
2025-12-18 00:11:01.507533 | TASK [Run test-setup role]
2025-12-18 00:11:01.528397 | controller | ok
2025-12-18 00:11:01.554746 | 
2025-12-18 00:11:01.554870 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-18 00:11:02.184139 | controller | ok
2025-12-18 00:11:02.193319 | 
2025-12-18 00:11:02.193467 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-18 00:11:02.565340 | controller | skipping: Conditional result was False
2025-12-18 00:11:02.604927 | 
2025-12-18 00:11:02.605108 | PLAY RECAP
2025-12-18 00:11:02.605160 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-18 00:11:02.605182 | 
2025-12-18 00:11:02.762030 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-18 00:11:02.763459 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-18 00:11:03.553732 | 
2025-12-18 00:11:03.553889 | PLAY [controller]
2025-12-18 00:11:03.578152 | 
2025-12-18 00:11:03.578318 | TASK [Create the /root directory]
2025-12-18 00:11:04.716344 | controller | ok
2025-12-18 00:11:04.729400 | 
2025-12-18 00:11:04.729545 | TASK [Install glibc-langpack-en]
2025-12-18 00:11:13.583534 | controller | ok: Nothing to do
2025-12-18 00:11:13.592310 | 
2025-12-18 00:11:13.592379 | TASK [Ensure controller directory exists]
2025-12-18 00:11:14.424467 | controller | changed
2025-12-18 00:11:14.434518 | 
2025-12-18 00:11:14.434674 | TASK [Install container runtime]
2025-12-18 00:11:14.502955 | controller | ok
2025-12-18 00:11:14.565533 | 
2025-12-18 00:11:14.565720 | LOOP [ensure-podman : Find distribution installation]
2025-12-18 00:11:14.604734 | controller | ok: "/var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-18 00:11:14.627324 | controller | included: /var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-18 00:11:14.654010 | 
2025-12-18 00:11:14.654160 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-18 00:13:21.828918 | controller | changed
2025-12-18 00:13:21.837448 | 
2025-12-18 00:13:21.837582 | TASK [ensure-podman : Fetch podman version]
2025-12-18 00:13:23.062521 | controller | Client:       Podman Engine
2025-12-18 00:13:23.093978 | controller | Version:      4.6.2
2025-12-18 00:13:23.094028 | controller | API Version:  4.6.2
2025-12-18 00:13:23.094037 | controller | Go Version:   go1.19.12
2025-12-18 00:13:23.094055 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-18 00:13:23.094064 | controller | OS/Arch:      linux/amd64
2025-12-18 00:13:23.708861 | controller | ok: Runtime: 0:00:00.274727
2025-12-18 00:13:23.716004 | 
2025-12-18 00:13:23.716466 | TASK [ensure-podman : Print podman version installed]
2025-12-18 00:13:23.747891 | Podman version: Client:       Podman Engine
2025-12-18 00:13:23.748290 | Version:      4.6.2
2025-12-18 00:13:23.748333 | API Version:  4.6.2
2025-12-18 00:13:23.748360 | Go Version:   go1.19.12
2025-12-18 00:13:23.748381 | Built:        Mon Aug 28 19:38:31 2023
2025-12-18 00:13:23.748401 | OS/Arch:      linux/amd64
2025-12-18 00:13:23.755714 | 
2025-12-18 00:13:23.755794 | TASK [ensure-podman : Validate podman engine]
2025-12-18 00:13:24.114940 | controller | skipping: Conditional result was False
2025-12-18 00:13:24.126500 | 
2025-12-18 00:13:24.126670 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-18 00:13:24.155084 | controller | skipping: Conditional result was False
2025-12-18 00:13:24.176369 | 
2025-12-18 00:13:24.176746 | TASK [Ensure python3.8 is present]
2025-12-18 00:13:24.192963 | controller | skipping: Conditional result was False
2025-12-18 00:13:24.202128 | 
2025-12-18 00:13:24.202258 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-18 00:13:24.225909 | controller | ok
2025-12-18 00:13:24.262339 | 
2025-12-18 00:13:24.262465 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-18 00:13:27.954478 | controller | ok: Nothing to do
2025-12-18 00:13:27.961535 | 
2025-12-18 00:13:27.961649 | TASK [our-ensure-python : Also install python3-devel]
2025-12-18 00:13:43.933496 | controller | changed
2025-12-18 00:13:43.948839 | 
2025-12-18 00:13:43.948976 | TASK [Run ensure-virtualenv role]
2025-12-18 00:13:43.972462 | controller | ok
2025-12-18 00:13:44.004005 | 
2025-12-18 00:13:44.004164 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-18 00:13:44.808540 | controller | /usr/bin/virtualenv
2025-12-18 00:13:45.412901 | controller | ok: Runtime: 0:00:00.004457
2025-12-18 00:13:45.422723 | 
2025-12-18 00:13:45.422822 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-18 00:13:45.467853 | controller | skipping: Conditional result was False
2025-12-18 00:13:45.468212 | controller | ok: All items complete
2025-12-18 00:13:45.468241 | 
2025-12-18 00:13:45.486945 | 
2025-12-18 00:13:45.487094 | TASK [Find the full path of the Python interpreter]
2025-12-18 00:13:46.273433 | controller | /usr/bin/python3
2025-12-18 00:13:46.845964 | controller | ok
2025-12-18 00:13:46.861530 | 
2025-12-18 00:13:46.862209 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-18 00:13:48.745114 | controller | created virtual environment CPython3.11.0.final.0-64 in 916ms
2025-12-18 00:13:48.830691 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-18 00:13:48.830745 | 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-18 00:13:48.830758 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-18 00:13:48.830777 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-18 00:13:49.260300 | controller | changed
2025-12-18 00:13:49.269862 | 
2025-12-18 00:13:49.269970 | TASK [Set selinux package]
2025-12-18 00:13:49.294023 | controller | ok
2025-12-18 00:13:49.302429 | 
2025-12-18 00:13:49.302524 | TASK [Set selinux package (Fedora)]
2025-12-18 00:13:49.337373 | controller | ok
2025-12-18 00:13:49.344773 | 
2025-12-18 00:13:49.344855 | TASK [Install selinux into virtualenv]
2025-12-18 00:13:52.864809 | controller | Collecting selinux-please-lie-to-me
2025-12-18 00:13:53.039317 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-18 00:13:53.648963 | controller | Collecting setuptools<50.0.0
2025-12-18 00:13:53.741921 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-18 00:13:53.801125 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.1 MB/s eta 0:00:00
2025-12-18 00:13:53.943834 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-18 00:13:53.944155 | controller |   Attempting uninstall: setuptools
2025-12-18 00:13:53.948101 | controller |     Found existing installation: setuptools 62.6.0
2025-12-18 00:13:54.062252 | controller |     Uninstalling setuptools-62.6.0:
2025-12-18 00:13:54.078147 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-18 00:13:54.871334 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-18 00:13:55.123870 | controller |
2025-12-18 00:13:55.411175 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-18 00:13:55.411228 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-18 00:13:55.746017 | controller | ok: Runtime: 0:00:05.251233
2025-12-18 00:13:55.754960 | 
2025-12-18 00:13:55.755082 | TASK [Install pytest-forked into virtualenv]
2025-12-18 00:13:57.454159 | controller | Collecting pytest-forked
2025-12-18 00:13:57.535228 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-18 00:13:57.633669 | controller | Collecting py
2025-12-18 00:13:57.637926 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-18 00:13:57.685926 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.1 MB/s eta 0:00:00
2025-12-18 00:13:57.904165 | controller | Collecting pytest>=3.10
2025-12-18 00:13:57.914082 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-18 00:13:57.945390 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 14.1 MB/s eta 0:00:00
2025-12-18 00:13:58.023886 | controller | Collecting iniconfig>=1.0.1
2025-12-18 00:13:58.029897 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-18 00:13:58.135498 | controller | Collecting packaging>=22
2025-12-18 00:13:58.146793 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-18 00:13:58.162499 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 4.8 MB/s eta 0:00:00
2025-12-18 00:13:58.232332 | controller | Collecting pluggy<2,>=1.5
2025-12-18 00:13:58.237933 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-18 00:13:58.331950 | controller | Collecting pygments>=2.7.2
2025-12-18 00:13:58.338202 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-18 00:13:58.388838 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 27.6 MB/s eta 0:00:00
2025-12-18 00:13:58.528909 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-18 00:14:01.080852 | 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-18 00:14:01.098197 | controller |
2025-12-18 00:14:01.340155 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-18 00:14:01.340209 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-18 00:14:01.635588 | controller | ok: Runtime: 0:00:04.738469
2025-12-18 00:14:01.644644 | 
2025-12-18 00:14:01.644809 | TASK [Update pip]
2025-12-18 00:14:03.068076 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-18 00:14:03.331198 | controller | Collecting pip
2025-12-18 00:14:03.404203 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-18 00:14:03.477185 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 26.5 MB/s eta 0:00:00
2025-12-18 00:14:03.618649 | controller | Installing collected packages: pip
2025-12-18 00:14:03.620058 | controller |   Attempting uninstall: pip
2025-12-18 00:14:03.626666 | controller |     Found existing installation: pip 22.2.2
2025-12-18 00:14:03.930962 | controller |     Uninstalling pip-22.2.2:
2025-12-18 00:14:03.959994 | controller |       Successfully uninstalled pip-22.2.2
2025-12-18 00:14:05.993417 | controller | Successfully installed pip-25.3
2025-12-18 00:14:06.533392 | controller | ok: Runtime: 0:00:03.821188
2025-12-18 00:14:06.543083 | 
2025-12-18 00:14:06.543209 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-18 00:14:07.580285 | controller | changed
2025-12-18 00:14:07.589083 | 
2025-12-18 00:14:07.589544 | TASK [Install ansible into virtualenv]
2025-12-18 00:14:08.933804 | controller | Processing ./src/github.com/ansible/ansible
2025-12-18 00:14:08.945067 | controller |   Installing build dependencies: started
2025-12-18 00:14:11.095821 | controller |   Installing build dependencies: finished with status 'done'
2025-12-18 00:14:11.098536 | controller |   Getting requirements to build wheel: started
2025-12-18 00:14:12.711352 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-18 00:14:13.744424 | controller |   Preparing metadata (pyproject.toml): started
2025-12-18 00:14:13.744473 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-18 00:14:13.748910 | 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-18 00:14:13.748947 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-18 00:14:14.531225 | controller | ERROR
2025-12-18 00:14:14.531453 | controller | {
2025-12-18 00:14:14.531485 | controller |   "delta": "0:00:05.609825",
2025-12-18 00:14:14.531506 | controller |   "end": "2025-12-18 00:14:13.932847",
2025-12-18 00:14:14.531525 | controller |   "msg": "non-zero return code",
2025-12-18 00:14:14.531559 | controller |   "rc": 1,
2025-12-18 00:14:14.531578 | controller |   "start": "2025-12-18 00:14:08.323022"
2025-12-18 00:14:14.531595 | controller | }
failure
2025-12-18 00:14:14.533624 | 
2025-12-18 00:14:14.533721 | PLAY RECAP
2025-12-18 00:14:14.533790 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-18 00:14:14.533814 | 
2025-12-18 00:14:14.683306 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-18 00:14:14.684377 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-18 00:14:15.373420 | 
2025-12-18 00:14:15.373642 | PLAY [all]
2025-12-18 00:14:15.400972 | 
2025-12-18 00:14:15.401167 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-18 00:14:17.260028 | controller | changed: non-zero return code
2025-12-18 00:14:17.267016 | 
2025-12-18 00:14:17.267131 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-18 00:14:17.283565 | controller | skipping: Conditional result was False
2025-12-18 00:14:17.293553 | 
2025-12-18 00:14:17.293660 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-18 00:14:17.322579 | 
2025-12-18 00:14:17.322791 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-18 00:14:17.358998 | 
2025-12-18 00:14:17.359215 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-18 00:14:17.378588 | controller | skipping: Conditional result was False
2025-12-18 00:14:17.387508 | 
2025-12-18 00:14:17.387604 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-18 00:14:17.421853 | 
2025-12-18 00:14:17.422056 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-18 00:14:17.436943 | controller | skipping: Conditional result was False
2025-12-18 00:14:17.445744 | 
2025-12-18 00:14:17.445861 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-18 00:14:17.460835 | controller | skipping: Conditional result was False
2025-12-18 00:14:17.469266 | 
2025-12-18 00:14:17.469396 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-18 00:14:17.496696 | controller | skipping: Conditional result was False
2025-12-18 00:14:17.532742 | 
2025-12-18 00:14:17.532865 | PLAY RECAP
2025-12-18 00:14:17.532915 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-18 00:14:17.532939 | 
2025-12-18 00:14:17.676939 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-18 00:14:17.677915 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-18 00:14:18.347847 | 
2025-12-18 00:14:18.348057 | PLAY [all:!appliance*]
2025-12-18 00:14:18.370470 | 
2025-12-18 00:14:18.370606 | TASK [unregister the node]
2025-12-18 00:14:18.727289 | controller | skipping: Conditional result was False
2025-12-18 00:14:18.734799 | 
2025-12-18 00:14:18.734941 | TASK [include_role : fetch-output]
2025-12-18 00:14:18.778864 | controller | ok
2025-12-18 00:14:18.822414 | 
2025-12-18 00:14:18.822563 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-18 00:14:18.888373 | controller | skipping: Conditional result was False
2025-12-18 00:14:18.898142 | 
2025-12-18 00:14:18.898295 | TASK [fetch-output : Set log path for single node]
2025-12-18 00:14:18.940896 | controller | ok
2025-12-18 00:14:18.948205 | 
2025-12-18 00:14:18.948300 | LOOP [fetch-output : Ensure local output dirs]
2025-12-18 00:14:19.369824 | controller -> localhost | ok: "/var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/logs"
2025-12-18 00:14:19.587519 | controller -> localhost | changed: "/var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/artifacts"
2025-12-18 00:14:19.822380 | controller -> localhost | changed: "/var/lib/zuul/builds/0686fc40d527479abf6e8fa87bed7cad/work/docs"
2025-12-18 00:14:19.849053 | 
2025-12-18 00:14:19.849279 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-18 00:14:22.099442 | controller | changed:
2025-12-18 00:14:22.099635 | controller | .d..t...... ./
2025-12-18 00:14:22.099662 | controller | cd+++++++++ controller/
2025-12-18 00:14:22.099717 | controller | changed: All items complete
2025-12-18 00:14:22.099740 | 
2025-12-18 00:14:24.147578 | controller | changed: .d..t...... ./
2025-12-18 00:14:26.201316 | controller | changed: .d..t...... ./
2025-12-18 00:14:26.237640 | 
2025-12-18 00:14:26.237829 | TASK [include_role : fetch-output-openshift]
2025-12-18 00:14:26.264042 | controller | skipping: Conditional result was False
2025-12-18 00:14:26.272870 | 
2025-12-18 00:14:26.273022 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-18 00:14:26.307555 | controller | skipping: Conditional result was False
2025-12-18 00:14:26.316847 | controller | skipping: Conditional result was False
2025-12-18 00:14:26.355786 | 
2025-12-18 00:14:26.355908 | PLAY [localhost]
2025-12-18 00:14:26.371120 | 
2025-12-18 00:14:26.371237 | TASK [Run Zuul manifest role]
2025-12-18 00:14:26.391755 | localhost | ok
2025-12-18 00:14:26.411436 | 
2025-12-18 00:14:26.411740 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-18 00:14:26.828997 | localhost | changed
2025-12-18 00:14:26.835553 | 
2025-12-18 00:14:26.835671 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-18 00:14:26.866475 | localhost | ok
2025-12-18 00:14:26.876040 | 
2025-12-18 00:14:26.876151 | TASK [Set zuul-log-path fact]
2025-12-18 00:14:26.896369 | localhost | ok
2025-12-18 00:14:26.942995 | 
2025-12-18 00:14:26.943115 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-18 00:14:26.972544 | localhost | ok
2025-12-18 00:14:26.982604 | 
2025-12-18 00:14:26.982784 | LOOP [Run upload-logs-swift role]
2025-12-18 00:14:27.018603 | localhost | Output suppressed because no_log was given
2025-12-18 00:14:27.052302 | 
2025-12-18 00:14:27.052460 | TASK [Set zuul-log-path fact]
2025-12-18 00:14:27.078518 | localhost | skipping: Conditional result was False
2025-12-18 00:14:27.086201 | 
2025-12-18 00:14:27.086325 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-18 00:14:27.512388 | localhost -> localhost | ok: Runtime: 0:00:00.005327
2025-12-18 00:14:27.518589 | 
2025-12-18 00:14:27.518710 | TASK [upload-logs-swift : Upload logs to swift]