2025-10-18 00:06:35.968529 | Job console starting...
2025-10-18 00:06:35.980312 | Updating repositories
2025-10-18 00:06:40.342274 | Preparing job workspace
2025-10-18 00:06:44.534347 | Running Ansible setup...
2025-10-18 00:06:51.460959 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-18 00:06:52.070128 | 
2025-10-18 00:06:52.070260 | PLAY [localhost]
2025-10-18 00:06:52.078980 | 
2025-10-18 00:06:52.079051 | TASK [Gathering Facts]
2025-10-18 00:06:53.086325 | localhost | ok
2025-10-18 00:06:53.117391 | 
2025-10-18 00:06:53.117582 | TASK [Setup log path fact]
2025-10-18 00:06:53.140938 | localhost | ok
2025-10-18 00:06:53.159083 | 
2025-10-18 00:06:53.159175 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-18 00:06:53.190163 | localhost | ok
2025-10-18 00:06:53.201139 | 
2025-10-18 00:06:53.201247 | TASK [emit-job-header : Print job information]
2025-10-18 00:06:53.256873 | # Job Information
2025-10-18 00:06:53.257124 | Ansible Version: 2.15.12
2025-10-18 00:06:53.257194 | Job: ansible-test-sanity-docker-milestone
2025-10-18 00:06:53.257241 | Pipeline: periodic
2025-10-18 00:06:53.257281 | Executor: ze02.softwarefactory-project.io
2025-10-18 00:06:53.257321 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-18 00:06:53.257366 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/1ed/ansible/1eda3fe4822749a9ac7a7799453e9fb4/
2025-10-18 00:06:53.257407 | Event ID: 475bf33318134110a1dbccf99c35efa3
2025-10-18 00:06:53.266553 | 
2025-10-18 00:06:53.266756 | LOOP [emit-job-header : Print node information]
2025-10-18 00:06:53.371512 | localhost | ok:
2025-10-18 00:06:53.371737 | localhost | # Node Information
2025-10-18 00:06:53.371765 | localhost | Inventory Hostname: controller
2025-10-18 00:06:53.371788 | localhost | Hostname: ip-172-16-8-53
2025-10-18 00:06:53.371814 | localhost | Username: zuul-worker
2025-10-18 00:06:53.371835 | localhost | Distro: Fedora 37
2025-10-18 00:06:53.371853 | localhost | Provider: ansible-us-east-2
2025-10-18 00:06:53.371870 | localhost | Region: us-east-2
2025-10-18 00:06:53.371887 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-18 00:06:53.371903 | localhost | Product Name: t3.small
2025-10-18 00:06:53.371920 | localhost | Interface IP: 18.221.6.76
2025-10-18 00:06:53.387462 | 
2025-10-18 00:06:53.387636 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-18 00:06:53.790086 | localhost -> localhost | changed
2025-10-18 00:06:53.798312 | 
2025-10-18 00:06:53.798422 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-18 00:06:54.663532 | localhost -> localhost | changed
2025-10-18 00:06:54.699986 | 
2025-10-18 00:06:54.700091 | PLAY [all:!appliance*]
2025-10-18 00:06:54.717297 | 
2025-10-18 00:06:54.717398 | TASK [include_role : start-zuul-console]
2025-10-18 00:06:54.737275 | controller | ok
2025-10-18 00:06:54.753229 | 
2025-10-18 00:06:54.753373 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-18 00:06:55.352017 | controller | ok
2025-10-18 00:06:55.362622 | 
2025-10-18 00:06:55.362780 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-18 00:06:56.540132 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-18 00:06:56.553975 | 
2025-10-18 00:06:56.554066 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-18 00:06:56.693983 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.700420 | 
2025-10-18 00:06:56.700646 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-18 00:06:56.724936 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.730998 | 
2025-10-18 00:06:56.731065 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-18 00:06:56.755177 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.770318 | 
2025-10-18 00:06:56.770478 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-18 00:06:56.798749 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.813780 | 
2025-10-18 00:06:56.813936 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-18 00:06:56.841940 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.857804 | 
2025-10-18 00:06:56.857954 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-18 00:06:56.886755 | controller | skipping: Conditional result was False
2025-10-18 00:06:56.910090 | 
2025-10-18 00:06:56.910180 | TASK [Disable Fedora Modular]
2025-10-18 00:06:57.467957 | controller | changed
2025-10-18 00:06:57.473936 | 
2025-10-18 00:06:57.474007 | TASK [Enable EPEL]
2025-10-18 00:06:57.500502 | controller | skipping: Conditional result was False
2025-10-18 00:06:57.508266 | 
2025-10-18 00:06:57.508431 | TASK [Register the RHEL node]
2025-10-18 00:06:57.666932 | 
2025-10-18 00:06:57.667188 | TASK [Show the subscription-manager status]
2025-10-18 00:06:57.806510 | controller | skipping: Conditional result was False
2025-10-18 00:06:57.817830 | 
2025-10-18 00:06:57.817932 | TASK [Enable EPEL on RHEL]
2025-10-18 00:06:58.005995 | controller | skipping: Conditional result was False
2025-10-18 00:06:58.014632 | 
2025-10-18 00:06:58.014743 | TASK [Install git and tox]
2025-10-18 00:10:26.544862 | controller | changed
2025-10-18 00:10:26.557843 | 
2025-10-18 00:10:26.558034 | TASK [include_role : prepare-workspace]
2025-10-18 00:10:26.585350 | controller | ok
2025-10-18 00:10:26.620605 | 
2025-10-18 00:10:26.620718 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-18 00:10:27.205215 | controller | ok
2025-10-18 00:10:27.218555 | 
2025-10-18 00:10:27.218736 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-18 00:10:40.084517 | controller | Output suppressed because no_log was given
2025-10-18 00:10:40.103107 | 
2025-10-18 00:10:40.103194 | TASK [include_role : prepare-workspace-openshift]
2025-10-18 00:10:40.131641 | controller | skipping: Conditional result was False
2025-10-18 00:10:40.160742 | 
2025-10-18 00:10:40.160826 | PLAY [all:!appliance]
2025-10-18 00:10:40.202820 | 
2025-10-18 00:10:40.202934 | TASK [Run add-build-sshkey role (RSA)]
2025-10-18 00:10:40.234046 | controller | ok
2025-10-18 00:10:40.253174 | 
2025-10-18 00:10:40.253269 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-18 00:10:40.504145 | controller -> localhost | ok
2025-10-18 00:10:40.522222 | 
2025-10-18 00:10:40.522372 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-18 00:10:40.570647 | controller | ok
2025-10-18 00:10:40.599139 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-18 00:10:40.606982 | 
2025-10-18 00:10:40.607185 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-18 00:10:41.153627 | controller -> localhost | Generating public/private rsa key pair.
2025-10-18 00:10:41.154169 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_rsa.
2025-10-18 00:10:41.154210 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_rsa.pub.
2025-10-18 00:10:41.154237 | controller -> localhost | The key fingerprint is:
2025-10-18 00:10:41.154260 | controller -> localhost | SHA256:A/VhRhOKVsXHWPGArv7kbZJ8ScH0N4xCC//OQ+Y0/Lc zuul-build-sshkey
2025-10-18 00:10:41.154282 | controller -> localhost | The key's randomart image is:
2025-10-18 00:10:41.154304 | controller -> localhost | +---[RSA 2048]----+
2025-10-18 00:10:41.154325 | controller -> localhost | |        o+O*+.   |
2025-10-18 00:10:41.154348 | controller -> localhost | |       + *+++o   |
2025-10-18 00:10:41.154369 | controller -> localhost | |      + ..=+..+  |
2025-10-18 00:10:41.154391 | controller -> localhost | |     . .  .+o..o.|
2025-10-18 00:10:41.154412 | controller -> localhost | |        S.  +. ..|
2025-10-18 00:10:41.154443 | controller -> localhost | |        ..  .B   |
2025-10-18 00:10:41.154472 | controller -> localhost | |       . ..oB.o  |
2025-10-18 00:10:41.154498 | controller -> localhost | |        .o+.+= ..|
2025-10-18 00:10:41.154524 | controller -> localhost | |         .o+. .Eo|
2025-10-18 00:10:41.154550 | controller -> localhost | +----[SHA256]-----+
2025-10-18 00:10:41.154609 | controller -> localhost | ok: Runtime: 0:00:00.092667
2025-10-18 00:10:41.163157 | 
2025-10-18 00:10:41.163242 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-18 00:10:41.196178 | controller | ok
2025-10-18 00:10:41.207747 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-18 00:10:41.217628 | 
2025-10-18 00:10:41.217739 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-18 00:10:41.242537 | controller | skipping: Conditional result was False
2025-10-18 00:10:41.257708 | 
2025-10-18 00:10:41.257867 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-18 00:10:41.954410 | controller | changed
2025-10-18 00:10:41.962531 | 
2025-10-18 00:10:41.962643 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-18 00:10:42.355764 | controller | ok
2025-10-18 00:10:42.363193 | 
2025-10-18 00:10:42.363277 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-18 00:10:43.769069 | controller | changed
2025-10-18 00:10:43.782168 | 
2025-10-18 00:10:43.782335 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-18 00:10:45.133810 | controller | changed
2025-10-18 00:10:45.150110 | 
2025-10-18 00:10:45.150295 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-18 00:10:45.178297 | controller | skipping: Conditional result was False
2025-10-18 00:10:45.188589 | 
2025-10-18 00:10:45.188785 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-18 00:10:45.530015 | controller -> localhost | changed
2025-10-18 00:10:45.551219 | 
2025-10-18 00:10:45.551375 | TASK [add-build-sshkey : Add back temp key]
2025-10-18 00:10:45.827180 | controller -> localhost | Identity added: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_rsa (zuul-build-sshkey)
2025-10-18 00:10:45.827625 | controller -> localhost | ok: Runtime: 0:00:00.009274
2025-10-18 00:10:45.845018 | 
2025-10-18 00:10:45.845235 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-18 00:10:46.337796 | controller | ok
2025-10-18 00:10:46.351421 | 
2025-10-18 00:10:46.351583 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-18 00:10:46.380411 | controller | skipping: Conditional result was False
2025-10-18 00:10:46.405743 | 
2025-10-18 00:10:46.405891 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-18 00:10:46.442505 | controller | ok
2025-10-18 00:10:46.466852 | 
2025-10-18 00:10:46.467008 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-18 00:10:46.749213 | controller -> localhost | ok
2025-10-18 00:10:46.764217 | 
2025-10-18 00:10:46.764361 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-18 00:10:46.810251 | controller | ok
2025-10-18 00:10:46.830613 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-18 00:10:46.839220 | 
2025-10-18 00:10:46.839312 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-18 00:10:47.132420 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-18 00:10:47.132823 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_ecdsa.
2025-10-18 00:10:47.132890 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_ecdsa.pub.
2025-10-18 00:10:47.132948 | controller -> localhost | The key fingerprint is:
2025-10-18 00:10:47.132991 | controller -> localhost | SHA256:8foKQqjkBRr6nNjHn2ZJpC3r8+OyN3s5Sz99RLPgv9o zuul-build-sshkey
2025-10-18 00:10:47.133036 | controller -> localhost | The key's randomart image is:
2025-10-18 00:10:47.133076 | controller -> localhost | +---[ECDSA 521]---+
2025-10-18 00:10:47.133115 | controller -> localhost | |                 |
2025-10-18 00:10:47.133152 | controller -> localhost | |                 |
2025-10-18 00:10:47.133189 | controller -> localhost | |..      .        |
2025-10-18 00:10:47.133226 | controller -> localhost | |o...  .  o  . o  |
2025-10-18 00:10:47.133263 | controller -> localhost | |o....+  S .. o o |
2025-10-18 00:10:47.133301 | controller -> localhost | |o*.+o o  .  . o  |
2025-10-18 00:10:47.133339 | controller -> localhost | |o.= ++..o. . o   |
2025-10-18 00:10:47.133377 | controller -> localhost | |   .+oB++o. ..o  |
2025-10-18 00:10:47.133446 | controller -> localhost | |   .oX*=o+o..oE. |
2025-10-18 00:10:47.133508 | controller -> localhost | +----[SHA256]-----+
2025-10-18 00:10:47.133610 | controller -> localhost | ok: Runtime: 0:00:00.014875
2025-10-18 00:10:47.148479 | 
2025-10-18 00:10:47.148620 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-18 00:10:47.194709 | controller | ok
2025-10-18 00:10:47.207462 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-18 00:10:47.216615 | 
2025-10-18 00:10:47.216704 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-18 00:10:47.241164 | controller | skipping: Conditional result was False
2025-10-18 00:10:47.250661 | 
2025-10-18 00:10:47.250781 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-18 00:10:47.749660 | controller | changed
2025-10-18 00:10:47.764802 | 
2025-10-18 00:10:47.764970 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-18 00:10:48.164269 | controller | ok
2025-10-18 00:10:48.177624 | 
2025-10-18 00:10:48.177811 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-18 00:10:49.596846 | controller | changed
2025-10-18 00:10:49.610904 | 
2025-10-18 00:10:49.611106 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-18 00:10:50.939405 | controller | changed
2025-10-18 00:10:50.945476 | 
2025-10-18 00:10:50.945549 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-18 00:10:50.970014 | controller | skipping: Conditional result was False
2025-10-18 00:10:50.976155 | 
2025-10-18 00:10:50.976228 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-18 00:10:51.234338 | controller -> localhost | changed
2025-10-18 00:10:51.247153 | 
2025-10-18 00:10:51.247267 | TASK [add-build-sshkey : Add back temp key]
2025-10-18 00:10:51.507392 | controller -> localhost | Identity added: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/1eda3fe4822749a9ac7a7799453e9fb4_id_ecdsa (zuul-build-sshkey)
2025-10-18 00:10:51.507721 | controller -> localhost | ok: Runtime: 0:00:00.007607
2025-10-18 00:10:51.515732 | 
2025-10-18 00:10:51.515862 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-18 00:10:51.841892 | controller | ok
2025-10-18 00:10:51.849012 | 
2025-10-18 00:10:51.849092 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-18 00:10:51.924220 | controller | skipping: Conditional result was False
2025-10-18 00:10:51.968562 | 
2025-10-18 00:10:51.968692 | TASK [include_role : remove-zuul-sshkey]
2025-10-18 00:10:51.982908 | controller | skipping: Conditional result was False
2025-10-18 00:10:51.989904 | 
2025-10-18 00:10:51.989971 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-18 00:10:52.309456 | controller | ok: "logs"
2025-10-18 00:10:52.309756 | controller | ok: All items complete
2025-10-18 00:10:52.309803 | 
2025-10-18 00:10:52.599159 | controller | ok: "artifacts"
2025-10-18 00:10:52.899183 | controller | ok: "docs"
2025-10-18 00:10:52.912247 | 
2025-10-18 00:10:52.912407 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-18 00:10:53.246922 | controller | changed: "logs"
2025-10-18 00:10:53.632542 | controller | changed: "artifacts"
2025-10-18 00:10:53.946766 | controller | changed: "docs"
2025-10-18 00:10:54.010365 | 
2025-10-18 00:10:54.010492 | PLAY RECAP
2025-10-18 00:10:54.010552 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-18 00:10:54.010589 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-18 00:10:54.010616 | 
2025-10-18 00:10:54.148238 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-18 00:10:54.149256 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-18 00:10:54.710273 | 
2025-10-18 00:10:54.710387 | PLAY [all]
2025-10-18 00:10:54.732600 | 
2025-10-18 00:10:54.732728 | TASK [Install binary dependencies]
2025-10-18 00:10:54.773346 | controller | ok
2025-10-18 00:10:54.793843 | 
2025-10-18 00:10:54.793966 | TASK [bindep : Include find tasks]
2025-10-18 00:10:54.823197 | controller | ok
2025-10-18 00:10:54.831130 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-18 00:10:54.837419 | 
2025-10-18 00:10:54.837493 | TASK [bindep : Look for bindep.txt]
2025-10-18 00:10:55.337132 | controller | ok
2025-10-18 00:10:55.343381 | 
2025-10-18 00:10:55.343472 | TASK [bindep : Define bindep_file fact]
2025-10-18 00:10:55.367371 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.373520 | 
2025-10-18 00:10:55.373599 | TASK [bindep : Look for other-requirements.txt]
2025-10-18 00:10:55.675763 | controller | ok
2025-10-18 00:10:55.681462 | 
2025-10-18 00:10:55.681548 | TASK [bindep : Define bindep_file fact]
2025-10-18 00:10:55.715859 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.721956 | 
2025-10-18 00:10:55.722049 | TASK [bindep : Look for bindep fallback file]
2025-10-18 00:10:55.756330 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.762717 | 
2025-10-18 00:10:55.762827 | TASK [bindep : Define bindep_file fact]
2025-10-18 00:10:55.796448 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.802878 | 
2025-10-18 00:10:55.802966 | TASK [bindep : Include bindep tasks]
2025-10-18 00:10:55.826547 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.833415 | 
2025-10-18 00:10:55.833479 | TASK [bindep : Include install tasks]
2025-10-18 00:10:55.857121 | controller | skipping: Conditional result was False
2025-10-18 00:10:55.871553 | 
2025-10-18 00:10:55.871735 | LOOP [bindep : Include package tasks]
2025-10-18 00:10:55.932804 | 
2025-10-18 00:10:55.933099 | TASK [Run test-setup role]
2025-10-18 00:10:55.958517 | controller | ok
2025-10-18 00:10:55.987748 | 
2025-10-18 00:10:55.987868 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-18 00:10:56.311781 | controller | ok
2025-10-18 00:10:56.324913 | 
2025-10-18 00:10:56.325165 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-18 00:10:56.472072 | controller | skipping: Conditional result was False
2025-10-18 00:10:56.529321 | 
2025-10-18 00:10:56.529405 | PLAY RECAP
2025-10-18 00:10:56.529460 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-18 00:10:56.529488 | 
2025-10-18 00:10:56.634036 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-18 00:10:56.635649 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-18 00:10:57.241355 | 
2025-10-18 00:10:57.241479 | PLAY [controller]
2025-10-18 00:10:57.261892 | 
2025-10-18 00:10:57.262027 | TASK [Create the /root directory]
2025-10-18 00:10:58.032135 | controller | ok
2025-10-18 00:10:58.037985 | 
2025-10-18 00:10:58.038072 | TASK [Install glibc-langpack-en]
2025-10-18 00:11:06.165161 | controller | ok: Nothing to do
2025-10-18 00:11:06.177913 | 
2025-10-18 00:11:06.178052 | TASK [Ensure controller directory exists]
2025-10-18 00:11:06.641063 | controller | changed
2025-10-18 00:11:06.653181 | 
2025-10-18 00:11:06.653332 | TASK [Install container runtime]
2025-10-18 00:11:06.733050 | controller | ok
2025-10-18 00:11:06.793919 | 
2025-10-18 00:11:06.794069 | LOOP [ensure-podman : Find distribution installation]
2025-10-18 00:11:06.838761 | controller | ok: "/var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-18 00:11:06.854398 | controller | included: /var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-18 00:11:06.867987 | 
2025-10-18 00:11:06.868078 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-18 00:13:39.352842 | controller | changed
2025-10-18 00:13:39.366593 | 
2025-10-18 00:13:39.366756 | TASK [ensure-podman : Fetch podman version]
2025-10-18 00:13:40.104403 | controller | Client:       Podman Engine
2025-10-18 00:13:40.132062 | controller | Version:      4.6.2
2025-10-18 00:13:40.132122 | controller | API Version:  4.6.2
2025-10-18 00:13:40.132139 | controller | Go Version:   go1.19.12
2025-10-18 00:13:40.132174 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-18 00:13:40.132191 | controller | OS/Arch:      linux/amd64
2025-10-18 00:13:40.513941 | controller | ok: Runtime: 0:00:00.220633
2025-10-18 00:13:40.520353 | 
2025-10-18 00:13:40.520428 | TASK [ensure-podman : Print podman version installed]
2025-10-18 00:13:40.554109 | Podman version: Client:       Podman Engine
2025-10-18 00:13:40.554275 | Version:      4.6.2
2025-10-18 00:13:40.554301 | API Version:  4.6.2
2025-10-18 00:13:40.554320 | Go Version:   go1.19.12
2025-10-18 00:13:40.554338 | Built:        Mon Aug 28 19:38:31 2023
2025-10-18 00:13:40.554355 | OS/Arch:      linux/amd64
2025-10-18 00:13:40.566063 | 
2025-10-18 00:13:40.566144 | TASK [ensure-podman : Validate podman engine]
2025-10-18 00:13:40.725815 | controller | skipping: Conditional result was False
2025-10-18 00:13:40.732027 | 
2025-10-18 00:13:40.732090 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-18 00:13:40.776437 | controller | skipping: Conditional result was False
2025-10-18 00:13:40.787847 | 
2025-10-18 00:13:40.787918 | TASK [Ensure python3.8 is present]
2025-10-18 00:13:40.842828 | controller | skipping: Conditional result was False
2025-10-18 00:13:40.849961 | 
2025-10-18 00:13:40.850087 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-18 00:13:40.911928 | controller | ok
2025-10-18 00:13:40.944612 | 
2025-10-18 00:13:40.944796 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-18 00:13:44.709438 | controller | ok: Nothing to do
2025-10-18 00:13:44.714786 | 
2025-10-18 00:13:44.714873 | TASK [our-ensure-python : Also install python3-devel]
2025-10-18 00:14:52.659284 | controller | changed
2025-10-18 00:14:52.673679 | 
2025-10-18 00:14:52.673821 | TASK [Run ensure-virtualenv role]
2025-10-18 00:14:52.697913 | controller | ok
2025-10-18 00:14:52.730040 | 
2025-10-18 00:14:52.730177 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-18 00:14:53.123208 | controller | /usr/bin/virtualenv
2025-10-18 00:14:53.397063 | controller | ok: Runtime: 0:00:00.004150
2025-10-18 00:14:53.405057 | 
2025-10-18 00:14:53.405152 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-18 00:14:53.430056 | controller | skipping: Conditional result was False
2025-10-18 00:14:53.430361 | controller | ok: All items complete
2025-10-18 00:14:53.430399 | 
2025-10-18 00:14:53.456138 | 
2025-10-18 00:14:53.456261 | TASK [Find the full path of the Python interpreter]
2025-10-18 00:14:53.879494 | controller | /usr/bin/python3
2025-10-18 00:14:54.106713 | controller | ok
2025-10-18 00:14:54.125861 | 
2025-10-18 00:14:54.125961 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-18 00:14:55.648899 | controller | created virtual environment CPython3.11.0.final.0-64 in 798ms
2025-10-18 00:14:55.705678 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-18 00:14:55.705734 | 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-10-18 00:14:55.705754 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-18 00:14:55.705778 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-18 00:14:55.781596 | controller | changed
2025-10-18 00:14:55.795381 | 
2025-10-18 00:14:55.795540 | TASK [Set selinux package]
2025-10-18 00:14:55.822100 | controller | ok
2025-10-18 00:14:55.827347 | 
2025-10-18 00:14:55.827425 | TASK [Set selinux package (Fedora)]
2025-10-18 00:14:55.857023 | controller | ok
2025-10-18 00:14:55.862875 | 
2025-10-18 00:14:55.862936 | TASK [Install selinux into virtualenv]
2025-10-18 00:14:58.517557 | controller | Collecting selinux-please-lie-to-me
2025-10-18 00:14:58.611498 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-18 00:14:59.145453 | controller | Collecting setuptools<50.0.0
2025-10-18 00:14:59.159586 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-18 00:14:59.267716 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 7.8 MB/s eta 0:00:00
2025-10-18 00:14:59.421516 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-18 00:14:59.421833 | controller |   Attempting uninstall: setuptools
2025-10-18 00:14:59.426781 | controller |     Found existing installation: setuptools 62.6.0
2025-10-18 00:14:59.540208 | controller |     Uninstalling setuptools-62.6.0:
2025-10-18 00:14:59.555477 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-18 00:15:00.297002 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-18 00:15:00.503902 | controller |
2025-10-18 00:15:00.741106 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-18 00:15:00.741154 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-18 00:15:01.029083 | controller | ok: Runtime: 0:00:04.407700
2025-10-18 00:15:01.048579 | 
2025-10-18 00:15:01.048781 | TASK [Install pytest-forked into virtualenv]
2025-10-18 00:15:03.955895 | controller | Collecting pytest-forked
2025-10-18 00:15:04.046630 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-18 00:15:04.108060 | controller | Collecting py
2025-10-18 00:15:04.121576 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-18 00:15:04.156534 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.4 MB/s eta 0:00:00
2025-10-18 00:15:04.366435 | controller | Collecting pytest>=3.10
2025-10-18 00:15:04.379962 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-18 00:15:04.444695 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 5.9 MB/s eta 0:00:00
2025-10-18 00:15:04.507695 | controller | Collecting iniconfig>=1
2025-10-18 00:15:04.522977 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-18 00:15:04.606331 | controller | Collecting packaging>=20
2025-10-18 00:15:04.620929 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-18 00:15:04.633683 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.4 MB/s eta 0:00:00
2025-10-18 00:15:04.691347 | controller | Collecting pluggy<2,>=1.5
2025-10-18 00:15:04.704633 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-18 00:15:04.795283 | controller | Collecting pygments>=2.7.2
2025-10-18 00:15:04.809321 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-18 00:15:04.936880 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 9.8 MB/s eta 0:00:00
2025-10-18 00:15:05.091181 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-18 00:15:07.357897 | controller | Successfully installed iniconfig-2.1.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-10-18 00:15:07.374137 | controller |
2025-10-18 00:15:07.554003 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-18 00:15:07.554055 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-18 00:15:07.758869 | controller | ok: Runtime: 0:00:04.762864
2025-10-18 00:15:07.767885 | 
2025-10-18 00:15:07.768005 | TASK [Update pip]
2025-10-18 00:15:08.870550 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-18 00:15:09.105873 | controller | Collecting pip
2025-10-18 00:15:09.194261 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-18 00:15:09.390090 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 9.1 MB/s eta 0:00:00
2025-10-18 00:15:09.542270 | controller | Installing collected packages: pip
2025-10-18 00:15:09.542608 | controller |   Attempting uninstall: pip
2025-10-18 00:15:09.547072 | controller |     Found existing installation: pip 22.2.2
2025-10-18 00:15:09.804397 | controller |     Uninstalling pip-22.2.2:
2025-10-18 00:15:09.834205 | controller |       Successfully uninstalled pip-22.2.2
2025-10-18 00:15:11.575223 | controller | Successfully installed pip-25.2
2025-10-18 00:15:11.930452 | controller | ok: Runtime: 0:00:03.499499
2025-10-18 00:15:11.936034 | 
2025-10-18 00:15:11.936094 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-18 00:15:12.486882 | controller | changed
2025-10-18 00:15:12.494599 | 
2025-10-18 00:15:12.494727 | TASK [Install ansible into virtualenv]
2025-10-18 00:15:13.689898 | controller | Processing ./src/github.com/ansible/ansible
2025-10-18 00:15:13.696260 | controller |   Installing build dependencies: started
2025-10-18 00:15:15.680964 | controller |   Installing build dependencies: finished with status 'done'
2025-10-18 00:15:15.682129 | controller |   Getting requirements to build wheel: started
2025-10-18 00:15:17.212384 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-18 00:15:17.212527 | controller |   Preparing metadata (pyproject.toml): started
2025-10-18 00:15:18.151385 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-18 00:15:18.155018 | 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-10-18 00:15:18.159991 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-18 00:15:18.640336 | controller | ERROR
2025-10-18 00:15:18.640496 | controller | {
2025-10-18 00:15:18.640526 | controller |   "delta": "0:00:05.294902",
2025-10-18 00:15:18.640545 | controller |   "end": "2025-10-18 00:15:18.315568",
2025-10-18 00:15:18.640562 | controller |   "msg": "non-zero return code",
2025-10-18 00:15:18.640587 | controller |   "rc": 1,
2025-10-18 00:15:18.640603 | controller |   "start": "2025-10-18 00:15:13.020666"
2025-10-18 00:15:18.640621 | controller | }
failure
2025-10-18 00:15:18.642426 | 
2025-10-18 00:15:18.642477 | PLAY RECAP
2025-10-18 00:15:18.642521 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-18 00:15:18.642540 | 
2025-10-18 00:15:18.800685 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-18 00:15:18.801977 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-18 00:15:19.429306 | 
2025-10-18 00:15:19.429424 | PLAY [all]
2025-10-18 00:15:19.451042 | 
2025-10-18 00:15:19.451140 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-18 00:15:20.271545 | controller | changed: non-zero return code
2025-10-18 00:15:20.284608 | 
2025-10-18 00:15:20.284830 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-18 00:15:20.312982 | controller | skipping: Conditional result was False
2025-10-18 00:15:20.326405 | 
2025-10-18 00:15:20.326592 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-18 00:15:20.369297 | 
2025-10-18 00:15:20.369578 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-18 00:15:20.411851 | 
2025-10-18 00:15:20.412201 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-18 00:15:20.430835 | controller | skipping: Conditional result was False
2025-10-18 00:15:20.446623 | 
2025-10-18 00:15:20.446852 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-18 00:15:20.484656 | 
2025-10-18 00:15:20.484880 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-18 00:15:20.510435 | controller | skipping: Conditional result was False
2025-10-18 00:15:20.518233 | 
2025-10-18 00:15:20.518320 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-18 00:15:20.543395 | controller | skipping: Conditional result was False
2025-10-18 00:15:20.551619 | 
2025-10-18 00:15:20.551726 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-18 00:15:20.576834 | controller | skipping: Conditional result was False
2025-10-18 00:15:20.611774 | 
2025-10-18 00:15:20.611846 | PLAY RECAP
2025-10-18 00:15:20.611899 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-18 00:15:20.611927 | 
2025-10-18 00:15:20.707760 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-18 00:15:20.708708 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-18 00:15:21.310743 | 
2025-10-18 00:15:21.310852 | PLAY [all:!appliance*]
2025-10-18 00:15:21.330962 | 
2025-10-18 00:15:21.331040 | TASK [unregister the node]
2025-10-18 00:15:21.468288 | controller | skipping: Conditional result was False
2025-10-18 00:15:21.480519 | 
2025-10-18 00:15:21.480713 | TASK [include_role : fetch-output]
2025-10-18 00:15:21.528560 | controller | ok
2025-10-18 00:15:21.568513 | 
2025-10-18 00:15:21.568695 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-18 00:15:21.656259 | controller | skipping: Conditional result was False
2025-10-18 00:15:21.669558 | 
2025-10-18 00:15:21.669789 | TASK [fetch-output : Set log path for single node]
2025-10-18 00:15:21.729384 | controller | ok
2025-10-18 00:15:21.741597 | 
2025-10-18 00:15:21.741776 | LOOP [fetch-output : Ensure local output dirs]
2025-10-18 00:15:22.252306 | controller -> localhost | ok: "/var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/logs"
2025-10-18 00:15:22.507914 | controller -> localhost | changed: "/var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/artifacts"
2025-10-18 00:15:22.739980 | controller -> localhost | changed: "/var/lib/zuul/builds/1eda3fe4822749a9ac7a7799453e9fb4/work/docs"
2025-10-18 00:15:22.753796 | 
2025-10-18 00:15:22.753872 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-18 00:15:24.039101 | controller | changed:
2025-10-18 00:15:24.039291 | controller | .d..t...... ./
2025-10-18 00:15:24.039320 | controller | cd+++++++++ controller/
2025-10-18 00:15:24.039356 | controller | changed: All items complete
2025-10-18 00:15:24.039376 | 
2025-10-18 00:15:25.131164 | controller | changed: .d..t...... ./
2025-10-18 00:15:26.253516 | controller | changed: .d..t...... ./
2025-10-18 00:15:26.293382 | 
2025-10-18 00:15:26.293744 | TASK [include_role : fetch-output-openshift]
2025-10-18 00:15:26.320770 | controller | skipping: Conditional result was False
2025-10-18 00:15:26.331007 | 
2025-10-18 00:15:26.331145 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-18 00:15:26.366451 | controller | skipping: Conditional result was False
2025-10-18 00:15:26.379883 | controller | skipping: Conditional result was False
2025-10-18 00:15:26.427977 | 
2025-10-18 00:15:26.428117 | PLAY [localhost]
2025-10-18 00:15:26.447096 | 
2025-10-18 00:15:26.447246 | TASK [Run Zuul manifest role]
2025-10-18 00:15:26.468481 | localhost | ok
2025-10-18 00:15:26.489374 | 
2025-10-18 00:15:26.489493 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-18 00:15:26.917916 | localhost | changed
2025-10-18 00:15:26.922424 | 
2025-10-18 00:15:26.922486 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-18 00:15:26.962903 | localhost | ok
2025-10-18 00:15:26.973619 | 
2025-10-18 00:15:26.973722 | TASK [Set zuul-log-path fact]
2025-10-18 00:15:26.993703 | localhost | ok
2025-10-18 00:15:27.011900 | 
2025-10-18 00:15:27.012012 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-18 00:15:27.052507 | localhost | ok
2025-10-18 00:15:27.064230 | 
2025-10-18 00:15:27.064334 | LOOP [Run upload-logs-swift role]
2025-10-18 00:15:27.099790 | localhost | Output suppressed because no_log was given
2025-10-18 00:15:27.146968 | 
2025-10-18 00:15:27.147068 | TASK [Set zuul-log-path fact]
2025-10-18 00:15:27.172427 | localhost | skipping: Conditional result was False
2025-10-18 00:15:27.179504 | 
2025-10-18 00:15:27.179595 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-18 00:15:27.592394 | localhost -> localhost | ok: Runtime: 0:00:00.004966
2025-10-18 00:15:27.597763 | 
2025-10-18 00:15:27.597831 | TASK [upload-logs-swift : Upload logs to swift]