2025-11-12 00:21:45.691269 | Job console starting...
2025-11-12 00:21:45.701464 | Updating repositories
2025-11-12 00:21:45.829859 | Preparing job workspace
2025-11-12 00:21:49.427858 | Running Ansible setup...
2025-11-12 00:21:54.246216 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-12 00:21:54.882734 | 
2025-11-12 00:21:54.882876 | PLAY [localhost]
2025-11-12 00:21:54.892197 | 
2025-11-12 00:21:54.892300 | TASK [Gathering Facts]
2025-11-12 00:21:55.912640 | localhost | ok
2025-11-12 00:21:55.948554 | 
2025-11-12 00:21:55.948662 | TASK [Setup log path fact]
2025-11-12 00:21:55.966691 | localhost | ok
2025-11-12 00:21:55.979472 | 
2025-11-12 00:21:55.979542 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-12 00:21:56.007021 | localhost | ok
2025-11-12 00:21:56.014884 | 
2025-11-12 00:21:56.014956 | TASK [emit-job-header : Print job information]
2025-11-12 00:21:56.052843 | # Job Information
2025-11-12 00:21:56.052986 | Ansible Version: 2.15.12
2025-11-12 00:21:56.053017 | Job: ansible-test-sanity-docker-milestone
2025-11-12 00:21:56.053038 | Pipeline: periodic
2025-11-12 00:21:56.053057 | Executor: ze04.softwarefactory-project.io
2025-11-12 00:21:56.053075 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-12 00:21:56.053097 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/150/ansible/1500749b46bd4bb4970642e6637fa841/
2025-11-12 00:21:56.053116 | Event ID: edca0ab7305f4724aa2c2c639624c9e2
2025-11-12 00:21:56.056795 | 
2025-11-12 00:21:56.056864 | LOOP [emit-job-header : Print node information]
2025-11-12 00:21:56.150148 | localhost | ok:
2025-11-12 00:21:56.150311 | localhost | # Node Information
2025-11-12 00:21:56.150343 | localhost | Inventory Hostname: controller
2025-11-12 00:21:56.150363 | localhost | Hostname: np0005518888
2025-11-12 00:21:56.150382 | localhost | Username: zuul
2025-11-12 00:21:56.150405 | localhost | Distro: Fedora 37
2025-11-12 00:21:56.150425 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-11-12 00:21:56.150442 | localhost | Region: ca-ymq-1
2025-11-12 00:21:56.150460 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-12 00:21:56.150478 | localhost | Product Name: OpenStack Nova
2025-11-12 00:21:56.150495 | localhost | Interface IP: 162.253.55.221
2025-11-12 00:21:56.160524 | 
2025-11-12 00:21:56.160670 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-12 00:21:56.552763 | localhost -> localhost | changed
2025-11-12 00:21:56.558704 | 
2025-11-12 00:21:56.558787 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-12 00:21:57.407277 | localhost -> localhost | changed
2025-11-12 00:21:57.426029 | 
2025-11-12 00:21:57.426088 | PLAY [all:!appliance*]
2025-11-12 00:21:57.441863 | 
2025-11-12 00:21:57.441926 | TASK [include_role : start-zuul-console]
2025-11-12 00:21:57.460575 | controller | ok
2025-11-12 00:21:57.473926 | 
2025-11-12 00:21:57.473999 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-12 00:21:57.874809 | controller | ok
2025-11-12 00:21:57.898987 | 
2025-11-12 00:21:57.899169 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-12 00:21:59.020398 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-12 00:21:59.036647 | 
2025-11-12 00:21:59.036828 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-12 00:21:59.587107 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.600877 | 
2025-11-12 00:21:59.601020 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-12 00:21:59.627891 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.642180 | 
2025-11-12 00:21:59.642315 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-12 00:21:59.670673 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.684972 | 
2025-11-12 00:21:59.685109 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-12 00:21:59.711819 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.726527 | 
2025-11-12 00:21:59.726782 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-12 00:21:59.753374 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.768507 | 
2025-11-12 00:21:59.768651 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-12 00:21:59.795161 | controller | skipping: Conditional result was False
2025-11-12 00:21:59.819288 | 
2025-11-12 00:21:59.819425 | TASK [Disable Fedora Modular]
2025-11-12 00:22:00.068173 | controller | changed
2025-11-12 00:22:00.077252 | 
2025-11-12 00:22:00.077361 | TASK [Enable EPEL]
2025-11-12 00:22:00.104212 | controller | skipping: Conditional result was False
2025-11-12 00:22:00.116325 | 
2025-11-12 00:22:00.116450 | TASK [Register the RHEL node]
2025-11-12 00:22:00.672251 | 
2025-11-12 00:22:00.672436 | TASK [Show the subscription-manager status]
2025-11-12 00:22:01.243124 | controller | skipping: Conditional result was False
2025-11-12 00:22:01.258469 | 
2025-11-12 00:22:01.258612 | TASK [Enable EPEL on RHEL]
2025-11-12 00:22:01.814048 | controller | skipping: Conditional result was False
2025-11-12 00:22:01.822517 | 
2025-11-12 00:22:01.822617 | TASK [Install git and tox]
2025-11-12 00:23:23.357877 | controller | changed
2025-11-12 00:23:23.370007 | 
2025-11-12 00:23:23.370150 | TASK [include_role : prepare-workspace]
2025-11-12 00:23:23.402806 | controller | ok
2025-11-12 00:23:23.430504 | 
2025-11-12 00:23:23.430622 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-12 00:23:23.660787 | controller | ok
2025-11-12 00:23:23.674314 | 
2025-11-12 00:23:23.674430 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-12 00:23:35.554379 | controller | Output suppressed because no_log was given
2025-11-12 00:23:35.571882 | 
2025-11-12 00:23:35.572028 | TASK [include_role : prepare-workspace-openshift]
2025-11-12 00:23:35.587247 | controller | skipping: Conditional result was False
2025-11-12 00:23:35.651235 | 
2025-11-12 00:23:35.651331 | PLAY [all:!appliance]
2025-11-12 00:23:35.668307 | 
2025-11-12 00:23:35.668392 | TASK [Run add-build-sshkey role (RSA)]
2025-11-12 00:23:35.688219 | controller | ok
2025-11-12 00:23:35.704479 | 
2025-11-12 00:23:35.704554 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-12 00:23:35.956658 | controller -> localhost | ok
2025-11-12 00:23:35.963500 | 
2025-11-12 00:23:35.963572 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-12 00:23:35.983882 | controller | ok
2025-11-12 00:23:35.997989 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-12 00:23:36.004501 | 
2025-11-12 00:23:36.004564 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-12 00:23:36.517915 | controller -> localhost | Generating public/private rsa key pair.
2025-11-12 00:23:36.518118 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_rsa.
2025-11-12 00:23:36.518150 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_rsa.pub.
2025-11-12 00:23:36.518173 | controller -> localhost | The key fingerprint is:
2025-11-12 00:23:36.518194 | controller -> localhost | SHA256:EWUk0ucT5OgXL4AybEkG/9J28p9gz4b7yDI1/+3BApM zuul-build-sshkey
2025-11-12 00:23:36.518215 | controller -> localhost | The key's randomart image is:
2025-11-12 00:23:36.518236 | controller -> localhost | +---[RSA 2048]----+
2025-11-12 00:23:36.518256 | controller -> localhost | |  ..o ..o+=      |
2025-11-12 00:23:36.518275 | controller -> localhost | |   = . o.*o      |
2025-11-12 00:23:36.518295 | controller -> localhost | |    B . +oo.     |
2025-11-12 00:23:36.518314 | controller -> localhost | |   . = . oo+     |
2025-11-12 00:23:36.518333 | controller -> localhost | |    . = S E..    |
2025-11-12 00:23:36.518361 | controller -> localhost | |     o +o. + .   |
2025-11-12 00:23:36.518384 | controller -> localhost | |       .++  . o  |
2025-11-12 00:23:36.518404 | controller -> localhost | |      oo.*o. o . |
2025-11-12 00:23:36.518425 | controller -> localhost | |       o++*...o  |
2025-11-12 00:23:36.518447 | controller -> localhost | +----[SHA256]-----+
2025-11-12 00:23:36.518520 | controller -> localhost | ok: Runtime: 0:00:00.135094
2025-11-12 00:23:36.525609 | 
2025-11-12 00:23:36.525714 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-12 00:23:36.555860 | controller | ok
2025-11-12 00:23:36.565886 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-12 00:23:36.575764 | 
2025-11-12 00:23:36.575836 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-12 00:23:36.599800 | controller | skipping: Conditional result was False
2025-11-12 00:23:36.607685 | 
2025-11-12 00:23:36.607807 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-12 00:23:37.108119 | controller | changed
2025-11-12 00:23:37.121799 | 
2025-11-12 00:23:37.121936 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-12 00:23:37.357609 | controller | ok
2025-11-12 00:23:37.372052 | 
2025-11-12 00:23:37.372194 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-12 00:23:37.984103 | controller | changed
2025-11-12 00:23:37.999078 | 
2025-11-12 00:23:37.999224 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-12 00:23:38.620327 | controller | changed
2025-11-12 00:23:38.635603 | 
2025-11-12 00:23:38.635801 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-12 00:23:38.664807 | controller | skipping: Conditional result was False
2025-11-12 00:23:38.679852 | 
2025-11-12 00:23:38.680029 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-12 00:23:39.131012 | controller -> localhost | changed
2025-11-12 00:23:39.151969 | 
2025-11-12 00:23:39.152118 | TASK [add-build-sshkey : Add back temp key]
2025-11-12 00:23:39.483003 | controller -> localhost | Identity added: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_rsa (zuul-build-sshkey)
2025-11-12 00:23:39.483248 | controller -> localhost | ok: Runtime: 0:00:00.009623
2025-11-12 00:23:39.491209 | 
2025-11-12 00:23:39.491280 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-12 00:23:39.920088 | controller | ok
2025-11-12 00:23:39.951167 | 
2025-11-12 00:23:39.951319 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-12 00:23:39.998309 | controller | skipping: Conditional result was False
2025-11-12 00:23:40.015136 | 
2025-11-12 00:23:40.015231 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-12 00:23:40.047797 | controller | ok
2025-11-12 00:23:40.073118 | 
2025-11-12 00:23:40.073213 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-12 00:23:40.352669 | controller -> localhost | ok
2025-11-12 00:23:40.366569 | 
2025-11-12 00:23:40.366668 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-12 00:23:40.389954 | controller | ok
2025-11-12 00:23:40.405619 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-12 00:23:40.426188 | 
2025-11-12 00:23:40.426257 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-12 00:23:40.715103 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-12 00:23:40.715435 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_ecdsa.
2025-11-12 00:23:40.715474 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_ecdsa.pub.
2025-11-12 00:23:40.715553 | controller -> localhost | The key fingerprint is:
2025-11-12 00:23:40.715585 | controller -> localhost | SHA256:Lbr6/xGZNaKMS22efGZo+s5hPllYSVlu21ChfCijKTM zuul-build-sshkey
2025-11-12 00:23:40.715616 | controller -> localhost | The key's randomart image is:
2025-11-12 00:23:40.715642 | controller -> localhost | +---[ECDSA 521]---+
2025-11-12 00:23:40.715667 | controller -> localhost | |           o. o. |
2025-11-12 00:23:40.715970 | controller -> localhost | |          oo +   |
2025-11-12 00:23:40.716006 | controller -> localhost | |         .+.X .  |
2025-11-12 00:23:40.716033 | controller -> localhost | |       + =oO *   |
2025-11-12 00:23:40.716058 | controller -> localhost | |      E So= . .  |
2025-11-12 00:23:40.716082 | controller -> localhost | |     . X.+..     |
2025-11-12 00:23:40.716107 | controller -> localhost | |      o Oo=      |
2025-11-12 00:23:40.716131 | controller -> localhost | |       Bo= .     |
2025-11-12 00:23:40.716156 | controller -> localhost | |    .o++*o.      |
2025-11-12 00:23:40.716183 | controller -> localhost | +----[SHA256]-----+
2025-11-12 00:23:40.716257 | controller -> localhost | ok: Runtime: 0:00:00.008458
2025-11-12 00:23:40.726168 | 
2025-11-12 00:23:40.726256 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-12 00:23:40.763222 | controller | ok
2025-11-12 00:23:40.772966 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-12 00:23:40.782031 | 
2025-11-12 00:23:40.782121 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-12 00:23:40.806945 | controller | skipping: Conditional result was False
2025-11-12 00:23:40.830604 | 
2025-11-12 00:23:40.830840 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-12 00:23:41.117897 | controller | changed
2025-11-12 00:23:41.133064 | 
2025-11-12 00:23:41.133209 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-12 00:23:41.360472 | controller | ok
2025-11-12 00:23:41.375006 | 
2025-11-12 00:23:41.375147 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-12 00:23:42.062490 | controller | changed
2025-11-12 00:23:42.075068 | 
2025-11-12 00:23:42.075207 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-12 00:23:42.728525 | controller | changed
2025-11-12 00:23:42.741260 | 
2025-11-12 00:23:42.741408 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-12 00:23:42.768922 | controller | skipping: Conditional result was False
2025-11-12 00:23:42.787465 | 
2025-11-12 00:23:42.787660 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-12 00:23:43.092956 | controller -> localhost | changed
2025-11-12 00:23:43.117531 | 
2025-11-12 00:23:43.117723 | TASK [add-build-sshkey : Add back temp key]
2025-11-12 00:23:43.450791 | controller -> localhost | Identity added: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/1500749b46bd4bb4970642e6637fa841_id_ecdsa (zuul-build-sshkey)
2025-11-12 00:23:43.451116 | controller -> localhost | ok: Runtime: 0:00:00.012339
2025-11-12 00:23:43.494611 | 
2025-11-12 00:23:43.494778 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-12 00:23:43.711647 | controller | ok
2025-11-12 00:23:43.727505 | 
2025-11-12 00:23:43.727753 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-12 00:23:43.765105 | controller | skipping: Conditional result was False
2025-11-12 00:23:43.781792 | 
2025-11-12 00:23:43.781932 | TASK [include_role : remove-zuul-sshkey]
2025-11-12 00:23:43.807197 | controller | skipping: Conditional result was False
2025-11-12 00:23:43.816721 | 
2025-11-12 00:23:43.816859 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-12 00:23:44.055729 | controller | ok: "logs"
2025-11-12 00:23:44.056208 | controller | ok: All items complete
2025-11-12 00:23:44.056285 | 
2025-11-12 00:23:44.244408 | controller | ok: "artifacts"
2025-11-12 00:23:44.448792 | controller | ok: "docs"
2025-11-12 00:23:44.455962 | 
2025-11-12 00:23:44.456064 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-12 00:23:44.703216 | controller | changed: "logs"
2025-11-12 00:23:44.899829 | controller | changed: "artifacts"
2025-11-12 00:23:45.117487 | controller | changed: "docs"
2025-11-12 00:23:45.182549 | 
2025-11-12 00:23:45.182835 | PLAY RECAP
2025-11-12 00:23:45.182920 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-12 00:23:45.182959 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-12 00:23:45.182985 | 
2025-11-12 00:23:45.397262 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-12 00:23:45.398437 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-12 00:23:45.990073 | 
2025-11-12 00:23:45.990181 | PLAY [all]
2025-11-12 00:23:46.013415 | 
2025-11-12 00:23:46.013551 | TASK [Install binary dependencies]
2025-11-12 00:23:46.068208 | controller | ok
2025-11-12 00:23:46.088197 | 
2025-11-12 00:23:46.088307 | TASK [bindep : Include find tasks]
2025-11-12 00:23:46.128023 | controller | ok
2025-11-12 00:23:46.136973 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-12 00:23:46.144722 | 
2025-11-12 00:23:46.144798 | TASK [bindep : Look for bindep.txt]
2025-11-12 00:23:46.504269 | controller | ok
2025-11-12 00:23:46.512327 | 
2025-11-12 00:23:46.512420 | TASK [bindep : Define bindep_file fact]
2025-11-12 00:23:46.548478 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.557023 | 
2025-11-12 00:23:46.557113 | TASK [bindep : Look for other-requirements.txt]
2025-11-12 00:23:46.769583 | controller | ok
2025-11-12 00:23:46.778167 | 
2025-11-12 00:23:46.778257 | TASK [bindep : Define bindep_file fact]
2025-11-12 00:23:46.813000 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.821609 | 
2025-11-12 00:23:46.821732 | TASK [bindep : Look for bindep fallback file]
2025-11-12 00:23:46.847703 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.854737 | 
2025-11-12 00:23:46.854825 | TASK [bindep : Define bindep_file fact]
2025-11-12 00:23:46.878317 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.884439 | 
2025-11-12 00:23:46.884529 | TASK [bindep : Include bindep tasks]
2025-11-12 00:23:46.908268 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.914397 | 
2025-11-12 00:23:46.914468 | TASK [bindep : Include install tasks]
2025-11-12 00:23:46.957938 | controller | skipping: Conditional result was False
2025-11-12 00:23:46.965187 | 
2025-11-12 00:23:46.965256 | LOOP [bindep : Include package tasks]
2025-11-12 00:23:47.049130 | 
2025-11-12 00:23:47.049480 | TASK [Run test-setup role]
2025-11-12 00:23:47.093903 | controller | ok
2025-11-12 00:23:47.120414 | 
2025-11-12 00:23:47.120690 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-12 00:28:57.993531 | controller | ok
2025-11-12 00:28:58.009824 | 
2025-11-12 00:28:58.010011 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-12 00:28:58.564454 | controller | skipping: Conditional result was False
2025-11-12 00:28:58.621929 | 
2025-11-12 00:28:58.622050 | PLAY RECAP
2025-11-12 00:28:58.622107 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-12 00:28:58.622135 | 
2025-11-12 00:28:58.727341 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-12 00:28:58.728267 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-12 00:28:59.327858 | 
2025-11-12 00:28:59.327995 | PLAY [controller]
2025-11-12 00:28:59.348143 | 
2025-11-12 00:28:59.348254 | TASK [Create the /root directory]
2025-11-12 00:28:59.942797 | controller | ok
2025-11-12 00:28:59.950445 | 
2025-11-12 00:28:59.950518 | TASK [Install glibc-langpack-en]
2025-11-12 00:29:04.048738 | controller | ok: Nothing to do
2025-11-12 00:29:04.058284 | 
2025-11-12 00:29:04.058389 | TASK [Ensure controller directory exists]
2025-11-12 00:29:04.300126 | controller | changed
2025-11-12 00:29:04.312316 | 
2025-11-12 00:29:04.312448 | TASK [Install container runtime]
2025-11-12 00:29:04.378768 | controller | ok
2025-11-12 00:29:04.437238 | 
2025-11-12 00:29:04.437357 | LOOP [ensure-podman : Find distribution installation]
2025-11-12 00:29:04.459346 | controller | ok: "/var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-12 00:29:04.468723 | controller | included: /var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-12 00:29:04.476405 | 
2025-11-12 00:29:04.476508 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-12 00:30:10.047197 | controller | changed
2025-11-12 00:30:10.061839 | 
2025-11-12 00:30:10.061975 | TASK [ensure-podman : Fetch podman version]
2025-11-12 00:30:10.638996 | controller | Client:       Podman Engine
2025-11-12 00:30:10.668040 | controller | Version:      4.6.2
2025-11-12 00:30:10.668067 | controller | API Version:  4.6.2
2025-11-12 00:30:10.668075 | controller | Go Version:   go1.19.12
2025-11-12 00:30:10.668095 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-12 00:30:10.668103 | controller | OS/Arch:      linux/amd64
2025-11-12 00:30:11.117566 | controller | ok: Runtime: 0:00:00.222829
2025-11-12 00:30:11.128986 | 
2025-11-12 00:30:11.129109 | TASK [ensure-podman : Print podman version installed]
2025-11-12 00:30:11.180014 | Podman version: Client:       Podman Engine
2025-11-12 00:30:11.180195 | Version:      4.6.2
2025-11-12 00:30:11.180234 | API Version:  4.6.2
2025-11-12 00:30:11.180262 | Go Version:   go1.19.12
2025-11-12 00:30:11.180287 | Built:        Mon Aug 28 19:38:31 2023
2025-11-12 00:30:11.180314 | OS/Arch:      linux/amd64
2025-11-12 00:30:11.188237 | 
2025-11-12 00:30:11.188336 | TASK [ensure-podman : Validate podman engine]
2025-11-12 00:30:11.729744 | controller | skipping: Conditional result was False
2025-11-12 00:30:11.744950 | 
2025-11-12 00:30:11.745118 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-12 00:30:11.761765 | controller | skipping: Conditional result was False
2025-11-12 00:30:11.790060 | 
2025-11-12 00:30:11.790169 | TASK [Ensure python3.8 is present]
2025-11-12 00:30:11.804717 | controller | skipping: Conditional result was False
2025-11-12 00:30:11.814762 | 
2025-11-12 00:30:11.814858 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-12 00:30:11.836899 | controller | ok
2025-11-12 00:30:11.864820 | 
2025-11-12 00:30:11.864949 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-12 00:30:13.478989 | controller | ok: Nothing to do
2025-11-12 00:30:13.486899 | 
2025-11-12 00:30:13.486992 | TASK [our-ensure-python : Also install python3-devel]
2025-11-12 00:30:23.602390 | controller | changed
2025-11-12 00:30:23.626230 | 
2025-11-12 00:30:23.626412 | TASK [Run ensure-virtualenv role]
2025-11-12 00:30:23.655977 | controller | ok
2025-11-12 00:30:23.703101 | 
2025-11-12 00:30:23.703283 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-12 00:30:23.960362 | controller | /usr/bin/virtualenv
2025-11-12 00:30:24.244524 | controller | ok: Runtime: 0:00:00.003917
2025-11-12 00:30:24.258077 | 
2025-11-12 00:30:24.258219 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-12 00:30:24.282827 | controller | skipping: Conditional result was False
2025-11-12 00:30:24.283420 | controller | ok: All items complete
2025-11-12 00:30:24.283505 | 
2025-11-12 00:30:24.321433 | 
2025-11-12 00:30:24.321618 | TASK [Find the full path of the Python interpreter]
2025-11-12 00:30:24.611260 | controller | /usr/bin/python3
2025-11-12 00:30:24.896733 | controller | ok
2025-11-12 00:30:24.902526 | 
2025-11-12 00:30:24.902595 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-12 00:30:25.880597 | controller | created virtual environment CPython3.11.0.final.0-64 in 649ms
2025-11-12 00:30:25.911777 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-12 00:30:25.912404 | 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-11-12 00:30:25.912627 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-12 00:30:25.912720 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-12 00:30:26.431132 | controller | changed
2025-11-12 00:30:26.438448 | 
2025-11-12 00:30:26.438543 | TASK [Set selinux package]
2025-11-12 00:30:26.458570 | controller | ok
2025-11-12 00:30:26.467576 | 
2025-11-12 00:30:26.467717 | TASK [Set selinux package (Fedora)]
2025-11-12 00:30:26.517399 | controller | ok
2025-11-12 00:30:26.522665 | 
2025-11-12 00:30:26.522747 | TASK [Install selinux into virtualenv]
2025-11-12 00:30:27.866037 | controller | Collecting selinux-please-lie-to-me
2025-11-12 00:30:27.907398 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-12 00:30:28.223926 | controller | Collecting setuptools<50.0.0
2025-11-12 00:30:28.229459 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-12 00:30:28.269179 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.0 MB/s eta 0:00:00
2025-11-12 00:30:28.356922 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-12 00:30:28.357169 | controller |   Attempting uninstall: setuptools
2025-11-12 00:30:28.359737 | controller |     Found existing installation: setuptools 62.6.0
2025-11-12 00:30:28.422052 | controller |     Uninstalling setuptools-62.6.0:
2025-11-12 00:30:28.430689 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-12 00:30:28.825478 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-12 00:30:28.958308 | controller |
2025-11-12 00:30:29.087600 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-12 00:30:29.087664 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-12 00:30:29.575478 | controller | ok: Runtime: 0:00:02.351852
2025-11-12 00:30:29.589237 | 
2025-11-12 00:30:29.589391 | TASK [Install pytest-forked into virtualenv]
2025-11-12 00:30:30.275301 | controller | Collecting pytest-forked
2025-11-12 00:30:30.319432 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-12 00:30:30.373241 | controller | Collecting py
2025-11-12 00:30:30.398359 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-12 00:30:30.416772 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.8 MB/s eta 0:00:00
2025-11-12 00:30:30.515832 | controller | Collecting pytest>=3.10
2025-11-12 00:30:30.520884 | controller |   Downloading pytest-9.0.0-py3-none-any.whl (373 kB)
2025-11-12 00:30:30.542473 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.4/373.4 kB 19.6 MB/s eta 0:00:00
2025-11-12 00:30:30.580681 | controller | Collecting iniconfig>=1.0.1
2025-11-12 00:30:30.584435 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-12 00:30:30.631510 | controller | Collecting packaging>=22
2025-11-12 00:30:30.636683 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-12 00:30:30.645856 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.9 MB/s eta 0:00:00
2025-11-12 00:30:30.679767 | controller | Collecting pluggy<2,>=1.5
2025-11-12 00:30:30.684054 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-12 00:30:30.732509 | controller | Collecting pygments>=2.7.2
2025-11-12 00:30:30.755042 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-12 00:30:30.799351 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 30.1 MB/s eta 0:00:00
2025-11-12 00:30:30.867348 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-12 00:30:31.978181 | 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.0 pytest-forked-1.6.0
2025-11-12 00:30:31.987923 | controller |
2025-11-12 00:30:32.077365 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-12 00:30:32.077381 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-12 00:30:32.158119 | controller | ok: Runtime: 0:00:02.213799
2025-11-12 00:30:32.170911 | 
2025-11-12 00:30:32.171001 | TASK [Update pip]
2025-11-12 00:30:32.711758 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-12 00:30:32.846053 | controller | Collecting pip
2025-11-12 00:30:32.880163 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-12 00:30:32.933344 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.8 MB/s eta 0:00:00
2025-11-12 00:30:33.003162 | controller | Installing collected packages: pip
2025-11-12 00:30:33.003940 | controller |   Attempting uninstall: pip
2025-11-12 00:30:33.006325 | controller |     Found existing installation: pip 22.2.2
2025-11-12 00:30:33.145360 | controller |     Uninstalling pip-22.2.2:
2025-11-12 00:30:33.161123 | controller |       Successfully uninstalled pip-22.2.2
2025-11-12 00:30:33.977951 | controller | Successfully installed pip-25.3
2025-11-12 00:30:34.217830 | controller | ok: Runtime: 0:00:01.669760
2025-11-12 00:30:34.229901 | 
2025-11-12 00:30:34.230088 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-12 00:30:34.476790 | controller | changed
2025-11-12 00:30:34.490716 | 
2025-11-12 00:30:34.490880 | TASK [Install ansible into virtualenv]
2025-11-12 00:30:35.072406 | controller | Processing ./src/github.com/ansible/ansible
2025-11-12 00:30:35.076046 | controller |   Installing build dependencies: started
2025-11-12 00:30:36.113798 | controller |   Installing build dependencies: finished with status 'done'
2025-11-12 00:30:36.114521 | controller |   Getting requirements to build wheel: started
2025-11-12 00:30:36.885353 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-12 00:30:36.886194 | controller |   Preparing metadata (pyproject.toml): started
2025-11-12 00:30:37.397934 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-12 00:30:37.400819 | 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-11-12 00:30:37.404714 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-12 00:30:37.590279 | controller | ERROR
2025-11-12 00:30:37.590863 | controller | {
2025-11-12 00:30:37.590946 | controller |   "delta": "0:00:02.728541",
2025-11-12 00:30:37.591031 | controller |   "end": "2025-11-12 00:30:37.504541",
2025-11-12 00:30:37.591073 | controller |   "msg": "non-zero return code",
2025-11-12 00:30:37.591131 | controller |   "rc": 1,
2025-11-12 00:30:37.591170 | controller |   "start": "2025-11-12 00:30:34.776000"
2025-11-12 00:30:37.591206 | controller | }
failure
2025-11-12 00:30:37.594132 | 
2025-11-12 00:30:37.594236 | PLAY RECAP
2025-11-12 00:30:37.594327 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-12 00:30:37.594376 | 
2025-11-12 00:30:37.734747 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-12 00:30:37.737071 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-12 00:30:38.411939 | 
2025-11-12 00:30:38.412120 | PLAY [all]
2025-11-12 00:30:38.434712 | 
2025-11-12 00:30:38.434805 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-12 00:30:38.897134 | controller | changed: non-zero return code
2025-11-12 00:30:38.914181 | 
2025-11-12 00:30:38.914525 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-12 00:30:38.946006 | controller | skipping: Conditional result was False
2025-11-12 00:30:38.957159 | 
2025-11-12 00:30:38.957282 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-12 00:30:39.009831 | 
2025-11-12 00:30:39.010126 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-12 00:30:39.047707 | 
2025-11-12 00:30:39.047950 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-12 00:30:39.074636 | controller | skipping: Conditional result was False
2025-11-12 00:30:39.085219 | 
2025-11-12 00:30:39.085332 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-12 00:30:39.122036 | 
2025-11-12 00:30:39.122320 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-12 00:30:39.150459 | controller | skipping: Conditional result was False
2025-11-12 00:30:39.160340 | 
2025-11-12 00:30:39.160439 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-12 00:30:39.187936 | controller | skipping: Conditional result was False
2025-11-12 00:30:39.197239 | 
2025-11-12 00:30:39.197340 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-12 00:30:39.223719 | controller | skipping: Conditional result was False
2025-11-12 00:30:39.264496 | 
2025-11-12 00:30:39.264734 | PLAY RECAP
2025-11-12 00:30:39.264825 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-12 00:30:39.264866 | 
2025-11-12 00:30:39.445162 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-12 00:30:39.446414 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-12 00:30:40.163892 | 
2025-11-12 00:30:40.164006 | PLAY [all:!appliance*]
2025-11-12 00:30:40.186494 | 
2025-11-12 00:30:40.186608 | TASK [unregister the node]
2025-11-12 00:30:40.719152 | controller | skipping: Conditional result was False
2025-11-12 00:30:40.732897 | 
2025-11-12 00:30:40.733073 | TASK [include_role : fetch-output]
2025-11-12 00:30:40.783857 | controller | ok
2025-11-12 00:30:40.835395 | 
2025-11-12 00:30:40.835612 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-12 00:30:40.904779 | controller | skipping: Conditional result was False
2025-11-12 00:30:40.921439 | 
2025-11-12 00:30:40.921629 | TASK [fetch-output : Set log path for single node]
2025-11-12 00:30:40.973384 | controller | ok
2025-11-12 00:30:40.986455 | 
2025-11-12 00:30:40.986613 | LOOP [fetch-output : Ensure local output dirs]
2025-11-12 00:30:41.526408 | controller -> localhost | ok: "/var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/logs"
2025-11-12 00:30:41.780873 | controller -> localhost | changed: "/var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/artifacts"
2025-11-12 00:30:41.998077 | controller -> localhost | changed: "/var/lib/zuul/builds/1500749b46bd4bb4970642e6637fa841/work/docs"
2025-11-12 00:30:42.009647 | 
2025-11-12 00:30:42.009735 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-12 00:30:42.717505 | controller | changed:
2025-11-12 00:30:42.718069 | controller | .d..t...... ./
2025-11-12 00:30:42.718145 | controller | cd+++++++++ controller/
2025-11-12 00:30:42.718220 | controller | changed: All items complete
2025-11-12 00:30:42.718267 | 
2025-11-12 00:30:43.265348 | controller | changed: .d..t...... ./
2025-11-12 00:30:43.784693 | controller | changed: .d..t...... ./
2025-11-12 00:30:43.802310 | 
2025-11-12 00:30:43.802429 | TASK [include_role : fetch-output-openshift]
2025-11-12 00:30:43.826609 | controller | skipping: Conditional result was False
2025-11-12 00:30:43.833454 | 
2025-11-12 00:30:43.833536 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-12 00:30:43.872481 | controller | skipping: Conditional result was False
2025-11-12 00:30:43.885384 | controller | skipping: Conditional result was False
2025-11-12 00:30:43.935411 | 
2025-11-12 00:30:43.935540 | PLAY [localhost]
2025-11-12 00:30:43.953407 | 
2025-11-12 00:30:43.953515 | TASK [Run Zuul manifest role]
2025-11-12 00:30:43.984162 | localhost | ok
2025-11-12 00:30:44.005741 | 
2025-11-12 00:30:44.005864 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-12 00:30:44.426179 | localhost | changed
2025-11-12 00:30:44.436798 | 
2025-11-12 00:30:44.436936 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-12 00:30:44.469336 | localhost | ok
2025-11-12 00:30:44.480359 | 
2025-11-12 00:30:44.480587 | TASK [Set zuul-log-path fact]
2025-11-12 00:30:44.501369 | localhost | ok
2025-11-12 00:30:44.520822 | 
2025-11-12 00:30:44.520930 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-12 00:30:44.550331 | localhost | ok
2025-11-12 00:30:44.560278 | 
2025-11-12 00:30:44.560372 | LOOP [Run upload-logs-swift role]
2025-11-12 00:30:44.596939 | localhost | Output suppressed because no_log was given
2025-11-12 00:30:44.635742 | 
2025-11-12 00:30:44.635875 | TASK [Set zuul-log-path fact]
2025-11-12 00:30:44.680954 | localhost | skipping: Conditional result was False
2025-11-12 00:30:44.689037 | 
2025-11-12 00:30:44.689138 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-12 00:30:45.095427 | localhost -> localhost | ok: Runtime: 0:00:00.008599
2025-11-12 00:30:45.143373 | 
2025-11-12 00:30:45.143510 | TASK [upload-logs-swift : Upload logs to swift]