2025-11-04 00:06:40.591290 | Job console starting...
2025-11-04 00:06:40.600179 | Updating repositories
2025-11-04 00:06:43.549250 | Preparing job workspace
2025-11-04 00:06:47.630400 | Running Ansible setup...
2025-11-04 00:06:56.140299 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-04 00:06:56.787467 | 
2025-11-04 00:06:56.787587 | PLAY [localhost]
2025-11-04 00:06:56.796592 | 
2025-11-04 00:06:56.796669 | TASK [Gathering Facts]
2025-11-04 00:06:57.754106 | localhost | ok
2025-11-04 00:06:57.783310 | 
2025-11-04 00:06:57.783421 | TASK [Setup log path fact]
2025-11-04 00:06:57.814988 | localhost | ok
2025-11-04 00:06:57.833377 | 
2025-11-04 00:06:57.833514 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-04 00:06:57.866866 | localhost | ok
2025-11-04 00:06:57.878969 | 
2025-11-04 00:06:57.879065 | TASK [emit-job-header : Print job information]
2025-11-04 00:06:57.920819 | # Job Information
2025-11-04 00:06:57.920996 | Ansible Version: 2.15.12
2025-11-04 00:06:57.921040 | Job: ansible-test-sanity-docker-milestone
2025-11-04 00:06:57.921071 | Pipeline: periodic
2025-11-04 00:06:57.921099 | Executor: ze04.softwarefactory-project.io
2025-11-04 00:06:57.921127 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-04 00:06:57.921158 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/79f/ansible/79f8eb4ef6884841950425befcac17e5/
2025-11-04 00:06:57.921186 | Event ID: 222ce06575fd4159b6a5d52bfe309fd7
2025-11-04 00:06:57.926599 | 
2025-11-04 00:06:57.926690 | LOOP [emit-job-header : Print node information]
2025-11-04 00:06:58.033756 | localhost | ok:
2025-11-04 00:06:58.033988 | localhost | # Node Information
2025-11-04 00:06:58.034030 | localhost | Inventory Hostname: controller
2025-11-04 00:06:58.034060 | localhost | Hostname: ip-172-16-213-68
2025-11-04 00:06:58.034089 | localhost | Username: zuul-worker
2025-11-04 00:06:58.034121 | localhost | Distro: Fedora 37
2025-11-04 00:06:58.034147 | localhost | Provider: ansible-us-east-2
2025-11-04 00:06:58.034170 | localhost | Region: us-east-2
2025-11-04 00:06:58.034194 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-04 00:06:58.034217 | localhost | Product Name: t3.small
2025-11-04 00:06:58.034242 | localhost | Interface IP: 3.17.133.221
2025-11-04 00:06:58.051664 | 
2025-11-04 00:06:58.051830 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-04 00:06:58.434754 | localhost -> localhost | changed
2025-11-04 00:06:58.440561 | 
2025-11-04 00:06:58.440637 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-04 00:06:59.287021 | localhost -> localhost | changed
2025-11-04 00:06:59.310631 | 
2025-11-04 00:06:59.310711 | PLAY [all:!appliance*]
2025-11-04 00:06:59.326855 | 
2025-11-04 00:06:59.326924 | TASK [include_role : start-zuul-console]
2025-11-04 00:06:59.345978 | controller | ok
2025-11-04 00:06:59.360035 | 
2025-11-04 00:06:59.360136 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-04 00:07:00.023035 | controller | ok
2025-11-04 00:07:00.058780 | 
2025-11-04 00:07:00.058978 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-04 00:07:01.455912 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-04 00:07:01.469592 | 
2025-11-04 00:07:01.469761 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-04 00:07:01.618892 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.643058 | 
2025-11-04 00:07:01.643220 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-04 00:07:01.680745 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.695195 | 
2025-11-04 00:07:01.695331 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-04 00:07:01.733823 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.746348 | 
2025-11-04 00:07:01.746485 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-04 00:07:01.773924 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.786508 | 
2025-11-04 00:07:01.786650 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-04 00:07:01.813918 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.826847 | 
2025-11-04 00:07:01.826989 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-04 00:07:01.854829 | controller | skipping: Conditional result was False
2025-11-04 00:07:01.877603 | 
2025-11-04 00:07:01.877784 | TASK [Disable Fedora Modular]
2025-11-04 00:07:02.708731 | controller | changed
2025-11-04 00:07:02.720474 | 
2025-11-04 00:07:02.720603 | TASK [Enable EPEL]
2025-11-04 00:07:02.747245 | controller | skipping: Conditional result was False
2025-11-04 00:07:02.759370 | 
2025-11-04 00:07:02.759502 | TASK [Register the RHEL node]
2025-11-04 00:07:02.918106 | 
2025-11-04 00:07:02.918262 | TASK [Show the subscription-manager status]
2025-11-04 00:07:03.060624 | controller | skipping: Conditional result was False
2025-11-04 00:07:03.100098 | 
2025-11-04 00:07:03.100216 | TASK [Enable EPEL on RHEL]
2025-11-04 00:07:03.239857 | controller | skipping: Conditional result was False
2025-11-04 00:07:03.253682 | 
2025-11-04 00:07:03.253881 | TASK [Install git and tox]
2025-11-04 00:08:26.425289 | controller | changed
2025-11-04 00:08:26.441434 | 
2025-11-04 00:08:26.441791 | TASK [include_role : prepare-workspace]
2025-11-04 00:08:26.482068 | controller | ok
2025-11-04 00:08:26.517286 | 
2025-11-04 00:08:26.517411 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-04 00:08:27.055344 | controller | ok
2025-11-04 00:08:27.070132 | 
2025-11-04 00:08:27.070325 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-04 00:08:42.523916 | controller | Output suppressed because no_log was given
2025-11-04 00:08:42.541309 | 
2025-11-04 00:08:42.541633 | TASK [include_role : prepare-workspace-openshift]
2025-11-04 00:08:42.581448 | controller | skipping: Conditional result was False
2025-11-04 00:08:42.608584 | 
2025-11-04 00:08:42.608669 | PLAY [all:!appliance]
2025-11-04 00:08:42.627604 | 
2025-11-04 00:08:42.627757 | TASK [Run add-build-sshkey role (RSA)]
2025-11-04 00:08:42.659863 | controller | ok
2025-11-04 00:08:42.680067 | 
2025-11-04 00:08:42.680155 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-04 00:08:42.949570 | controller -> localhost | ok
2025-11-04 00:08:42.958518 | 
2025-11-04 00:08:42.958584 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-04 00:08:43.025669 | controller | ok
2025-11-04 00:08:43.042178 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-04 00:08:43.049539 | 
2025-11-04 00:08:43.049613 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-04 00:08:43.574047 | controller -> localhost | Generating public/private rsa key pair.
2025-11-04 00:08:43.574334 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_rsa.
2025-11-04 00:08:43.574376 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_rsa.pub.
2025-11-04 00:08:43.574406 | controller -> localhost | The key fingerprint is:
2025-11-04 00:08:43.574434 | controller -> localhost | SHA256:rZTd8z6wPMoI7Hd+q8KhHD/O3AgcSLVOjBU7OrBBCwI zuul-build-sshkey
2025-11-04 00:08:43.574462 | controller -> localhost | The key's randomart image is:
2025-11-04 00:08:43.574489 | controller -> localhost | +---[RSA 2048]----+
2025-11-04 00:08:43.574515 | controller -> localhost | |E .   +.         |
2025-11-04 00:08:43.574542 | controller -> localhost | |.o . = o         |
2025-11-04 00:08:43.574568 | controller -> localhost | |  + o *          |
2025-11-04 00:08:43.574593 | controller -> localhost | |   = = . + .     |
2025-11-04 00:08:43.574617 | controller -> localhost | |  . + o S o o    |
2025-11-04 00:08:43.574652 | controller -> localhost | |     +.o..  .o   |
2025-11-04 00:08:43.574729 | controller -> localhost | |     .==.. . o.  |
2025-11-04 00:08:43.574761 | controller -> localhost | |     .o=*=. =..  |
2025-11-04 00:08:43.574788 | controller -> localhost | |      .o*=*+.o.. |
2025-11-04 00:08:43.574817 | controller -> localhost | +----[SHA256]-----+
2025-11-04 00:08:43.574882 | controller -> localhost | ok: Runtime: 0:00:00.098338
2025-11-04 00:08:43.586619 | 
2025-11-04 00:08:43.586727 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-04 00:08:43.625210 | controller | ok
2025-11-04 00:08:43.647953 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-04 00:08:43.663392 | 
2025-11-04 00:08:43.663509 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-04 00:08:43.689416 | controller | skipping: Conditional result was False
2025-11-04 00:08:43.697503 | 
2025-11-04 00:08:43.697572 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-04 00:08:44.329432 | controller | changed
2025-11-04 00:08:44.342514 | 
2025-11-04 00:08:44.342655 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-04 00:08:44.705241 | controller | ok
2025-11-04 00:08:44.714043 | 
2025-11-04 00:08:44.714145 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-04 00:08:46.051083 | controller | changed
2025-11-04 00:08:46.061929 | 
2025-11-04 00:08:46.062024 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-04 00:08:47.642841 | controller | changed
2025-11-04 00:08:47.660132 | 
2025-11-04 00:08:47.660323 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-04 00:08:47.687228 | controller | skipping: Conditional result was False
2025-11-04 00:08:47.694989 | 
2025-11-04 00:08:47.695061 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-04 00:08:48.065314 | controller -> localhost | changed
2025-11-04 00:08:48.091878 | 
2025-11-04 00:08:48.092075 | TASK [add-build-sshkey : Add back temp key]
2025-11-04 00:08:48.440392 | controller -> localhost | Identity added: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_rsa (zuul-build-sshkey)
2025-11-04 00:08:48.440662 | controller -> localhost | ok: Runtime: 0:00:00.008848
2025-11-04 00:08:48.450508 | 
2025-11-04 00:08:48.450617 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-04 00:08:48.920566 | controller | ok
2025-11-04 00:08:48.932759 | 
2025-11-04 00:08:48.932896 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-04 00:08:48.974056 | controller | skipping: Conditional result was False
2025-11-04 00:08:49.000362 | 
2025-11-04 00:08:49.000615 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-04 00:08:49.045777 | controller | ok
2025-11-04 00:08:49.071144 | 
2025-11-04 00:08:49.071342 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-04 00:08:49.374194 | controller -> localhost | ok
2025-11-04 00:08:49.383576 | 
2025-11-04 00:08:49.383673 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-04 00:08:49.417354 | controller | ok
2025-11-04 00:08:49.432470 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-04 00:08:49.441737 | 
2025-11-04 00:08:49.441822 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-04 00:08:49.826360 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-04 00:08:49.826654 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_ecdsa.
2025-11-04 00:08:49.826712 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_ecdsa.pub.
2025-11-04 00:08:49.826746 | controller -> localhost | The key fingerprint is:
2025-11-04 00:08:49.826767 | controller -> localhost | SHA256:rApfiX0tlsJH9p5IISwOibyDIvTu/GXaI+Jt2GzuVMs zuul-build-sshkey
2025-11-04 00:08:49.826787 | controller -> localhost | The key's randomart image is:
2025-11-04 00:08:49.826806 | controller -> localhost | +---[ECDSA 521]---+
2025-11-04 00:08:49.826823 | controller -> localhost | |                 |
2025-11-04 00:08:49.826855 | controller -> localhost | |                 |
2025-11-04 00:08:49.826873 | controller -> localhost | |                 |
2025-11-04 00:08:49.826890 | controller -> localhost | |.. . . .         |
2025-11-04 00:08:49.826907 | controller -> localhost | |.oo . o.S        |
2025-11-04 00:08:49.826924 | controller -> localhost | |o oo =o*.=       |
2025-11-04 00:08:49.826941 | controller -> localhost | |+o..*.BEB o      |
2025-11-04 00:08:49.826958 | controller -> localhost | |o +=oO=B + .     |
2025-11-04 00:08:49.826975 | controller -> localhost | |  o=X*..o o      |
2025-11-04 00:08:49.826992 | controller -> localhost | +----[SHA256]-----+
2025-11-04 00:08:49.827052 | controller -> localhost | ok: Runtime: 0:00:00.011620
2025-11-04 00:08:49.835060 | 
2025-11-04 00:08:49.835127 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-04 00:08:49.866742 | controller | ok
2025-11-04 00:08:49.874926 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-04 00:08:49.883932 | 
2025-11-04 00:08:49.883992 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-04 00:08:49.908991 | controller | skipping: Conditional result was False
2025-11-04 00:08:49.915413 | 
2025-11-04 00:08:49.915475 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-04 00:08:50.361958 | controller | changed
2025-11-04 00:08:50.367491 | 
2025-11-04 00:08:50.367551 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-04 00:08:50.692225 | controller | ok
2025-11-04 00:08:50.699444 | 
2025-11-04 00:08:50.699539 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-04 00:08:52.427004 | controller | changed
2025-11-04 00:08:52.444094 | 
2025-11-04 00:08:52.444281 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-04 00:08:53.774564 | controller | changed
2025-11-04 00:08:53.792254 | 
2025-11-04 00:08:53.792401 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-04 00:08:53.820971 | controller | skipping: Conditional result was False
2025-11-04 00:08:53.837027 | 
2025-11-04 00:08:53.837182 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-04 00:08:54.090174 | controller -> localhost | changed
2025-11-04 00:08:54.123202 | 
2025-11-04 00:08:54.123383 | TASK [add-build-sshkey : Add back temp key]
2025-11-04 00:08:54.434877 | controller -> localhost | Identity added: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/79f8eb4ef6884841950425befcac17e5_id_ecdsa (zuul-build-sshkey)
2025-11-04 00:08:54.435139 | controller -> localhost | ok: Runtime: 0:00:00.013173
2025-11-04 00:08:54.443442 | 
2025-11-04 00:08:54.443583 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-04 00:08:54.788123 | controller | ok
2025-11-04 00:08:54.804514 | 
2025-11-04 00:08:54.804759 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-04 00:08:54.842151 | controller | skipping: Conditional result was False
2025-11-04 00:08:54.858756 | 
2025-11-04 00:08:54.858928 | TASK [include_role : remove-zuul-sshkey]
2025-11-04 00:08:54.884874 | controller | skipping: Conditional result was False
2025-11-04 00:08:54.895177 | 
2025-11-04 00:08:54.895307 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-04 00:08:55.241286 | controller | ok: "logs"
2025-11-04 00:08:55.241750 | controller | ok: All items complete
2025-11-04 00:08:55.241823 | 
2025-11-04 00:08:55.526316 | controller | ok: "artifacts"
2025-11-04 00:08:55.854493 | controller | ok: "docs"
2025-11-04 00:08:55.871213 | 
2025-11-04 00:08:55.871301 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-04 00:08:56.209181 | controller | changed: "logs"
2025-11-04 00:08:56.500497 | controller | changed: "artifacts"
2025-11-04 00:08:56.771493 | controller | changed: "docs"
2025-11-04 00:08:56.821605 | 
2025-11-04 00:08:56.821772 | PLAY RECAP
2025-11-04 00:08:56.821833 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-04 00:08:56.821870 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-04 00:08:56.821896 | 
2025-11-04 00:08:56.932586 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-04 00:08:56.934288 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-04 00:08:57.578371 | 
2025-11-04 00:08:57.578489 | PLAY [all]
2025-11-04 00:08:57.601006 | 
2025-11-04 00:08:57.601138 | TASK [Install binary dependencies]
2025-11-04 00:08:57.682421 | controller | ok
2025-11-04 00:08:57.703984 | 
2025-11-04 00:08:57.704085 | TASK [bindep : Include find tasks]
2025-11-04 00:08:57.737100 | controller | ok
2025-11-04 00:08:57.747235 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-04 00:08:57.753570 | 
2025-11-04 00:08:57.753639 | TASK [bindep : Look for bindep.txt]
2025-11-04 00:08:58.290249 | controller | ok
2025-11-04 00:08:58.303999 | 
2025-11-04 00:08:58.304186 | TASK [bindep : Define bindep_file fact]
2025-11-04 00:08:58.322118 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.331882 | 
2025-11-04 00:08:58.332330 | TASK [bindep : Look for other-requirements.txt]
2025-11-04 00:08:58.637573 | controller | ok
2025-11-04 00:08:58.654589 | 
2025-11-04 00:08:58.654816 | TASK [bindep : Define bindep_file fact]
2025-11-04 00:08:58.683379 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.696349 | 
2025-11-04 00:08:58.696667 | TASK [bindep : Look for bindep fallback file]
2025-11-04 00:08:58.724321 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.737564 | 
2025-11-04 00:08:58.737782 | TASK [bindep : Define bindep_file fact]
2025-11-04 00:08:58.786253 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.803924 | 
2025-11-04 00:08:58.804124 | TASK [bindep : Include bindep tasks]
2025-11-04 00:08:58.831514 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.842501 | 
2025-11-04 00:08:58.842619 | TASK [bindep : Include install tasks]
2025-11-04 00:08:58.867713 | controller | skipping: Conditional result was False
2025-11-04 00:08:58.876329 | 
2025-11-04 00:08:58.876522 | LOOP [bindep : Include package tasks]
2025-11-04 00:08:58.936790 | 
2025-11-04 00:08:58.936993 | TASK [Run test-setup role]
2025-11-04 00:08:58.959508 | controller | ok
2025-11-04 00:08:58.986740 | 
2025-11-04 00:08:58.986852 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-04 00:08:59.280437 | controller | ok
2025-11-04 00:08:59.296570 | 
2025-11-04 00:08:59.296806 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-04 00:08:59.457574 | controller | skipping: Conditional result was False
2025-11-04 00:08:59.501480 | 
2025-11-04 00:08:59.501654 | PLAY RECAP
2025-11-04 00:08:59.501722 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-04 00:08:59.501746 | 
2025-11-04 00:08:59.622731 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-04 00:08:59.623737 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-04 00:09:00.262918 | 
2025-11-04 00:09:00.263050 | PLAY [controller]
2025-11-04 00:09:00.283380 | 
2025-11-04 00:09:00.283490 | TASK [Create the /root directory]
2025-11-04 00:09:00.985892 | controller | ok
2025-11-04 00:09:00.993545 | 
2025-11-04 00:09:00.993653 | TASK [Install glibc-langpack-en]
2025-11-04 00:09:09.355177 | controller | ok: Nothing to do
2025-11-04 00:09:09.369355 | 
2025-11-04 00:09:09.369546 | TASK [Ensure controller directory exists]
2025-11-04 00:09:09.792105 | controller | changed
2025-11-04 00:09:09.805947 | 
2025-11-04 00:09:09.806117 | TASK [Install container runtime]
2025-11-04 00:09:09.890443 | controller | ok
2025-11-04 00:09:09.952429 | 
2025-11-04 00:09:09.952571 | LOOP [ensure-podman : Find distribution installation]
2025-11-04 00:09:10.002007 | controller | ok: "/var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-04 00:09:10.022528 | controller | included: /var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-04 00:09:10.032003 | 
2025-11-04 00:09:10.032096 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-04 00:10:22.992315 | controller | changed
2025-11-04 00:10:23.002211 | 
2025-11-04 00:10:23.002380 | TASK [ensure-podman : Fetch podman version]
2025-11-04 00:10:23.707951 | controller | Client:       Podman Engine
2025-11-04 00:10:23.708030 | controller | Version:      4.6.2
2025-11-04 00:10:23.708059 | controller | API Version:  4.6.2
2025-11-04 00:10:23.708084 | controller | Go Version:   go1.19.12
2025-11-04 00:10:23.708121 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-04 00:10:23.708151 | controller | OS/Arch:      linux/amd64
2025-11-04 00:10:24.148490 | controller | ok: Runtime: 0:00:00.216067
2025-11-04 00:10:24.161825 | 
2025-11-04 00:10:24.161974 | TASK [ensure-podman : Print podman version installed]
2025-11-04 00:10:24.212433 | Podman version: Client:       Podman Engine
2025-11-04 00:10:24.212758 | Version:      4.6.2
2025-11-04 00:10:24.212964 | API Version:  4.6.2
2025-11-04 00:10:24.213018 | Go Version:   go1.19.12
2025-11-04 00:10:24.213060 | Built:        Mon Aug 28 19:38:31 2023
2025-11-04 00:10:24.213103 | OS/Arch:      linux/amd64
2025-11-04 00:10:24.226735 | 
2025-11-04 00:10:24.226998 | TASK [ensure-podman : Validate podman engine]
2025-11-04 00:10:24.397735 | controller | skipping: Conditional result was False
2025-11-04 00:10:24.405534 | 
2025-11-04 00:10:24.405661 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-04 00:10:24.431652 | controller | skipping: Conditional result was False
2025-11-04 00:10:24.444033 | 
2025-11-04 00:10:24.444169 | TASK [Ensure python3.8 is present]
2025-11-04 00:10:24.469904 | controller | skipping: Conditional result was False
2025-11-04 00:10:24.477199 | 
2025-11-04 00:10:24.477273 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-04 00:10:24.499971 | controller | ok
2025-11-04 00:10:24.522403 | 
2025-11-04 00:10:24.522485 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-04 00:10:28.074206 | controller | ok: Nothing to do
2025-11-04 00:10:28.080131 | 
2025-11-04 00:10:28.080276 | TASK [our-ensure-python : Also install python3-devel]
2025-11-04 00:10:41.083190 | controller | changed
2025-11-04 00:10:41.097522 | 
2025-11-04 00:10:41.097638 | TASK [Run ensure-virtualenv role]
2025-11-04 00:10:41.117967 | controller | ok
2025-11-04 00:10:41.141803 | 
2025-11-04 00:10:41.141919 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-04 00:10:41.512761 | controller | /usr/bin/virtualenv
2025-11-04 00:10:41.782602 | controller | ok: Runtime: 0:00:00.004431
2025-11-04 00:10:41.788696 | 
2025-11-04 00:10:41.788762 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-04 00:10:41.805671 | controller | skipping: Conditional result was False
2025-11-04 00:10:41.805927 | controller | ok: All items complete
2025-11-04 00:10:41.805954 | 
2025-11-04 00:10:41.824437 | 
2025-11-04 00:10:41.824540 | TASK [Find the full path of the Python interpreter]
2025-11-04 00:10:42.264272 | controller | /usr/bin/python3
2025-11-04 00:10:42.489343 | controller | ok
2025-11-04 00:10:42.498844 | 
2025-11-04 00:10:42.498974 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-04 00:10:43.928648 | controller | created virtual environment CPython3.11.0.final.0-64 in 768ms
2025-11-04 00:10:43.969363 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-04 00:10:43.969419 | 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-worker/.local/share/virtualenv)
2025-11-04 00:10:43.969437 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-04 00:10:43.969459 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-04 00:10:44.157282 | controller | changed
2025-11-04 00:10:44.173496 | 
2025-11-04 00:10:44.173714 | TASK [Set selinux package]
2025-11-04 00:10:44.207984 | controller | ok
2025-11-04 00:10:44.216021 | 
2025-11-04 00:10:44.216170 | TASK [Set selinux package (Fedora)]
2025-11-04 00:10:44.260253 | controller | ok
2025-11-04 00:10:44.268555 | 
2025-11-04 00:10:44.268668 | TASK [Install selinux into virtualenv]
2025-11-04 00:10:46.819914 | controller | Collecting selinux-please-lie-to-me
2025-11-04 00:10:46.910086 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-04 00:10:47.432661 | controller | Collecting setuptools<50.0.0
2025-11-04 00:10:47.446796 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-04 00:10:47.583365 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 6.3 MB/s eta 0:00:00
2025-11-04 00:10:47.728806 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-04 00:10:47.729103 | controller |   Attempting uninstall: setuptools
2025-11-04 00:10:47.733807 | controller |     Found existing installation: setuptools 62.6.0
2025-11-04 00:10:47.841648 | controller |     Uninstalling setuptools-62.6.0:
2025-11-04 00:10:47.856246 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-04 00:10:48.597869 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-04 00:10:48.796835 | controller |
2025-11-04 00:10:49.008208 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-04 00:10:49.008260 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-04 00:10:49.462827 | controller | ok: Runtime: 0:00:04.284082
2025-11-04 00:10:49.477999 | 
2025-11-04 00:10:49.478174 | TASK [Install pytest-forked into virtualenv]
2025-11-04 00:10:50.667305 | controller | Collecting pytest-forked
2025-11-04 00:10:50.754915 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-04 00:10:50.812035 | controller | Collecting py
2025-11-04 00:10:50.825635 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-04 00:10:50.862360 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.2 MB/s eta 0:00:00
2025-11-04 00:10:51.035124 | controller | Collecting pytest>=3.10
2025-11-04 00:10:51.048406 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-11-04 00:10:51.111004 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 6.1 MB/s eta 0:00:00
2025-11-04 00:10:51.165838 | controller | Collecting iniconfig>=1
2025-11-04 00:10:51.179341 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-04 00:10:51.245382 | controller | Collecting packaging>=20
2025-11-04 00:10:51.258641 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-04 00:10:51.270973 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.7 MB/s eta 0:00:00
2025-11-04 00:10:51.317381 | controller | Collecting pluggy<2,>=1.5
2025-11-04 00:10:51.328510 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-04 00:10:51.398763 | controller | Collecting pygments>=2.7.2
2025-11-04 00:10:51.411771 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-04 00:10:51.540359 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 9.7 MB/s eta 0:00:00
2025-11-04 00:10:51.668919 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-04 00:10:53.848162 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-11-04 00:10:53.863841 | controller |
2025-11-04 00:10:54.029719 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-04 00:10:54.029763 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-04 00:10:54.146079 | controller | ok: Runtime: 0:00:04.070796
2025-11-04 00:10:54.159197 | 
2025-11-04 00:10:54.159379 | TASK [Update pip]
2025-11-04 00:10:55.218919 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-04 00:10:55.462970 | controller | Collecting pip
2025-11-04 00:10:55.565030 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-04 00:10:55.804708 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 7.5 MB/s eta 0:00:00
2025-11-04 00:10:55.932198 | controller | Installing collected packages: pip
2025-11-04 00:10:55.932524 | controller |   Attempting uninstall: pip
2025-11-04 00:10:55.936692 | controller |     Found existing installation: pip 22.2.2
2025-11-04 00:10:56.188109 | controller |     Uninstalling pip-22.2.2:
2025-11-04 00:10:56.217437 | controller |       Successfully uninstalled pip-22.2.2
2025-11-04 00:10:57.869343 | controller | Successfully installed pip-25.3
2025-11-04 00:10:58.320992 | controller | ok: Runtime: 0:00:03.415068
2025-11-04 00:10:58.334142 | 
2025-11-04 00:10:58.334285 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-04 00:10:58.854665 | controller | changed
2025-11-04 00:10:58.867133 | 
2025-11-04 00:10:58.867275 | TASK [Install ansible into virtualenv]
2025-11-04 00:10:59.831268 | controller | Processing ./src/github.com/ansible/ansible
2025-11-04 00:10:59.837540 | controller |   Installing build dependencies: started
2025-11-04 00:11:01.750955 | controller |   Installing build dependencies: finished with status 'done'
2025-11-04 00:11:03.264913 | controller |   Getting requirements to build wheel: started
2025-11-04 00:11:03.264978 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-04 00:11:03.266354 | controller |   Preparing metadata (pyproject.toml): started
2025-11-04 00:11:04.177393 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-04 00:11:04.180622 | 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-04 00:11:04.185425 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-04 00:11:04.525389 | controller | ERROR
2025-11-04 00:11:04.525623 | controller | {
2025-11-04 00:11:04.525667 | controller |   "delta": "0:00:05.045740",
2025-11-04 00:11:04.525843 | controller |   "end": "2025-11-04 00:11:04.331818",
2025-11-04 00:11:04.525875 | controller |   "msg": "non-zero return code",
2025-11-04 00:11:04.525914 | controller |   "rc": 1,
2025-11-04 00:11:04.525965 | controller |   "start": "2025-11-04 00:10:59.286078"
2025-11-04 00:11:04.525994 | controller | }
failure
2025-11-04 00:11:04.527887 | 
2025-11-04 00:11:04.527953 | PLAY RECAP
2025-11-04 00:11:04.528020 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-04 00:11:04.528052 | 
2025-11-04 00:11:04.654796 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-04 00:11:04.656761 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-04 00:11:05.238507 | 
2025-11-04 00:11:05.238634 | PLAY [all]
2025-11-04 00:11:05.261217 | 
2025-11-04 00:11:05.261336 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-04 00:11:06.033216 | controller | changed: non-zero return code
2025-11-04 00:11:06.042166 | 
2025-11-04 00:11:06.042280 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-04 00:11:06.069301 | controller | skipping: Conditional result was False
2025-11-04 00:11:06.079815 | 
2025-11-04 00:11:06.079920 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-04 00:11:06.127247 | 
2025-11-04 00:11:06.127454 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-04 00:11:06.166854 | 
2025-11-04 00:11:06.167143 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-04 00:11:06.196056 | controller | skipping: Conditional result was False
2025-11-04 00:11:06.211134 | 
2025-11-04 00:11:06.211286 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-04 00:11:06.260939 | 
2025-11-04 00:11:06.261326 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-04 00:11:06.289466 | controller | skipping: Conditional result was False
2025-11-04 00:11:06.305803 | 
2025-11-04 00:11:06.306001 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-04 00:11:06.334277 | controller | skipping: Conditional result was False
2025-11-04 00:11:06.349438 | 
2025-11-04 00:11:06.349645 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-04 00:11:06.377394 | controller | skipping: Conditional result was False
2025-11-04 00:11:06.428242 | 
2025-11-04 00:11:06.428392 | PLAY RECAP
2025-11-04 00:11:06.428452 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-04 00:11:06.428482 | 
2025-11-04 00:11:06.568551 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-04 00:11:06.569801 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-04 00:11:07.173903 | 
2025-11-04 00:11:07.174031 | PLAY [all:!appliance*]
2025-11-04 00:11:07.196776 | 
2025-11-04 00:11:07.196900 | TASK [unregister the node]
2025-11-04 00:11:07.340788 | controller | skipping: Conditional result was False
2025-11-04 00:11:07.348500 | 
2025-11-04 00:11:07.348585 | TASK [include_role : fetch-output]
2025-11-04 00:11:07.380845 | controller | ok
2025-11-04 00:11:07.410361 | 
2025-11-04 00:11:07.410517 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-04 00:11:07.456273 | controller | skipping: Conditional result was False
2025-11-04 00:11:07.464985 | 
2025-11-04 00:11:07.465179 | TASK [fetch-output : Set log path for single node]
2025-11-04 00:11:07.508006 | controller | ok
2025-11-04 00:11:07.516005 | 
2025-11-04 00:11:07.516186 | LOOP [fetch-output : Ensure local output dirs]
2025-11-04 00:11:07.986478 | controller -> localhost | ok: "/var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/logs"
2025-11-04 00:11:08.267718 | controller -> localhost | changed: "/var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/artifacts"
2025-11-04 00:11:08.491964 | controller -> localhost | changed: "/var/lib/zuul/builds/79f8eb4ef6884841950425befcac17e5/work/docs"
2025-11-04 00:11:08.507409 | 
2025-11-04 00:11:08.507498 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-04 00:11:09.803061 | controller | changed:
2025-11-04 00:11:09.803405 | controller | .d..t...... ./
2025-11-04 00:11:09.803454 | controller | cd+++++++++ controller/
2025-11-04 00:11:09.803505 | controller | changed: All items complete
2025-11-04 00:11:09.803534 | 
2025-11-04 00:11:10.920787 | controller | changed: .d..t...... ./
2025-11-04 00:11:12.089149 | controller | changed: .d..t...... ./
2025-11-04 00:11:12.116523 | 
2025-11-04 00:11:12.116681 | TASK [include_role : fetch-output-openshift]
2025-11-04 00:11:12.143345 | controller | skipping: Conditional result was False
2025-11-04 00:11:12.153323 | 
2025-11-04 00:11:12.153442 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-04 00:11:12.202048 | controller | skipping: Conditional result was False
2025-11-04 00:11:12.221364 | controller | skipping: Conditional result was False
2025-11-04 00:11:12.263097 | 
2025-11-04 00:11:12.263256 | PLAY [localhost]
2025-11-04 00:11:12.275843 | 
2025-11-04 00:11:12.275915 | TASK [Run Zuul manifest role]
2025-11-04 00:11:12.294662 | localhost | ok
2025-11-04 00:11:12.309699 | 
2025-11-04 00:11:12.309814 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-04 00:11:12.760135 | localhost | changed
2025-11-04 00:11:12.765376 | 
2025-11-04 00:11:12.765438 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-04 00:11:12.793638 | localhost | ok
2025-11-04 00:11:12.801653 | 
2025-11-04 00:11:12.801730 | TASK [Set zuul-log-path fact]
2025-11-04 00:11:12.818895 | localhost | ok
2025-11-04 00:11:12.832512 | 
2025-11-04 00:11:12.832576 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-04 00:11:12.859939 | localhost | ok
2025-11-04 00:11:12.868924 | 
2025-11-04 00:11:12.868981 | LOOP [Run upload-logs-swift role]
2025-11-04 00:11:12.903126 | localhost | Output suppressed because no_log was given
2025-11-04 00:11:12.929030 | 
2025-11-04 00:11:12.929097 | TASK [Set zuul-log-path fact]
2025-11-04 00:11:12.953317 | localhost | skipping: Conditional result was False
2025-11-04 00:11:12.957963 | 
2025-11-04 00:11:12.958026 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-04 00:11:13.423457 | localhost -> localhost | ok: Runtime: 0:00:00.006033
2025-11-04 00:11:13.428901 | 
2025-11-04 00:11:13.428966 | TASK [upload-logs-swift : Upload logs to swift]