2025-10-04 00:18:24.009772 | Job console starting...
2025-10-04 00:18:24.021550 | Updating repositories
2025-10-04 00:18:24.136669 | Preparing job workspace
2025-10-04 00:18:28.157380 | Running Ansible setup...
2025-10-04 00:18:34.424307 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-04 00:18:35.083383 | 
2025-10-04 00:18:35.083515 | PLAY [localhost]
2025-10-04 00:18:35.092418 | 
2025-10-04 00:18:35.092506 | TASK [Gathering Facts]
2025-10-04 00:18:36.054238 | localhost | ok
2025-10-04 00:18:36.075624 | 
2025-10-04 00:18:36.075833 | TASK [Setup log path fact]
2025-10-04 00:18:36.096067 | localhost | ok
2025-10-04 00:18:36.113951 | 
2025-10-04 00:18:36.114099 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-04 00:18:36.144921 | localhost | ok
2025-10-04 00:18:36.155955 | 
2025-10-04 00:18:36.156099 | TASK [emit-job-header : Print job information]
2025-10-04 00:18:36.197266 | # Job Information
2025-10-04 00:18:36.197907 | Ansible Version: 2.15.12
2025-10-04 00:18:36.198160 | Job: ansible-test-sanity-docker-milestone
2025-10-04 00:18:36.198222 | Pipeline: periodic
2025-10-04 00:18:36.198266 | Executor: ze04.softwarefactory-project.io
2025-10-04 00:18:36.198308 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-04 00:18:36.198357 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a5f/ansible/a5ff2f29cd3d408fbc705fc38942a3ad/
2025-10-04 00:18:36.198433 | Event ID: 94a13ac06c46427a92df5bbab63fdd0f
2025-10-04 00:18:36.204522 | 
2025-10-04 00:18:36.204592 | LOOP [emit-job-header : Print node information]
2025-10-04 00:18:36.325520 | localhost | ok:
2025-10-04 00:18:36.325760 | localhost | # Node Information
2025-10-04 00:18:36.325789 | localhost | Inventory Hostname: controller
2025-10-04 00:18:36.325811 | localhost | Hostname: ip-172-16-99-252
2025-10-04 00:18:36.325834 | localhost | Username: zuul-worker
2025-10-04 00:18:36.325856 | localhost | Distro: Fedora 37
2025-10-04 00:18:36.325875 | localhost | Provider: ansible-us-east-2
2025-10-04 00:18:36.325913 | localhost | Region: us-east-2
2025-10-04 00:18:36.325932 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-04 00:18:36.325950 | localhost | Product Name: t3.small
2025-10-04 00:18:36.325966 | localhost | Interface IP: 18.224.5.20
2025-10-04 00:18:36.346303 | 
2025-10-04 00:18:36.346471 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-04 00:18:36.744401 | localhost -> localhost | changed
2025-10-04 00:18:36.750217 | 
2025-10-04 00:18:36.750288 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-04 00:18:37.591185 | localhost -> localhost | changed
2025-10-04 00:18:37.617504 | 
2025-10-04 00:18:37.617592 | PLAY [all:!appliance*]
2025-10-04 00:18:37.636700 | 
2025-10-04 00:18:37.636837 | TASK [include_role : start-zuul-console]
2025-10-04 00:18:37.658645 | controller | ok
2025-10-04 00:18:37.674021 | 
2025-10-04 00:18:37.674142 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-04 00:18:38.348074 | controller | ok
2025-10-04 00:18:38.360409 | 
2025-10-04 00:18:38.360527 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-04 00:18:40.072861 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-04 00:18:40.080496 | 
2025-10-04 00:18:40.080568 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-04 00:18:40.212188 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.221773 | 
2025-10-04 00:18:40.221885 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-04 00:18:40.277431 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.287248 | 
2025-10-04 00:18:40.287386 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-04 00:18:40.323271 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.331903 | 
2025-10-04 00:18:40.331997 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-04 00:18:40.367332 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.375462 | 
2025-10-04 00:18:40.375583 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-04 00:18:40.402940 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.413042 | 
2025-10-04 00:18:40.413180 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-04 00:18:40.439162 | controller | skipping: Conditional result was False
2025-10-04 00:18:40.461770 | 
2025-10-04 00:18:40.461982 | TASK [Disable Fedora Modular]
2025-10-04 00:18:41.260346 | controller | changed
2025-10-04 00:18:41.268979 | 
2025-10-04 00:18:41.269092 | TASK [Enable EPEL]
2025-10-04 00:18:41.296123 | controller | skipping: Conditional result was False
2025-10-04 00:18:41.305901 | 
2025-10-04 00:18:41.306029 | TASK [Register the RHEL node]
2025-10-04 00:18:41.468930 | 
2025-10-04 00:18:41.469216 | TASK [Show the subscription-manager status]
2025-10-04 00:18:41.636142 | controller | skipping: Conditional result was False
2025-10-04 00:18:41.684280 | 
2025-10-04 00:18:41.684413 | TASK [Enable EPEL on RHEL]
2025-10-04 00:18:41.840028 | controller | skipping: Conditional result was False
2025-10-04 00:18:41.852623 | 
2025-10-04 00:18:41.852908 | TASK [Install git and tox]
2025-10-04 00:20:10.375865 | controller | changed
2025-10-04 00:20:10.383064 | 
2025-10-04 00:20:10.383245 | TASK [include_role : prepare-workspace]
2025-10-04 00:20:10.431497 | controller | ok
2025-10-04 00:20:10.455262 | 
2025-10-04 00:20:10.455365 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-04 00:20:10.934421 | controller | ok
2025-10-04 00:20:10.951022 | 
2025-10-04 00:20:10.951172 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-04 00:20:23.522411 | controller | Output suppressed because no_log was given
2025-10-04 00:20:23.534452 | 
2025-10-04 00:20:23.534666 | TASK [include_role : prepare-workspace-openshift]
2025-10-04 00:20:23.561652 | controller | skipping: Conditional result was False
2025-10-04 00:20:23.585210 | 
2025-10-04 00:20:23.585326 | PLAY [all:!appliance]
2025-10-04 00:20:23.604183 | 
2025-10-04 00:20:23.604366 | TASK [Run add-build-sshkey role (RSA)]
2025-10-04 00:20:23.687777 | controller | ok
2025-10-04 00:20:23.706196 | 
2025-10-04 00:20:23.706380 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-04 00:20:24.012385 | controller -> localhost | ok
2025-10-04 00:20:24.020856 | 
2025-10-04 00:20:24.020929 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-04 00:20:24.052172 | controller | ok
2025-10-04 00:20:24.068121 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-04 00:20:24.073963 | 
2025-10-04 00:20:24.074030 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-04 00:20:24.669699 | controller -> localhost | Generating public/private rsa key pair.
2025-10-04 00:20:24.670083 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_rsa.
2025-10-04 00:20:24.670138 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_rsa.pub.
2025-10-04 00:20:24.670180 | controller -> localhost | The key fingerprint is:
2025-10-04 00:20:24.670219 | controller -> localhost | SHA256:ISppdP4Rm3OKAR6sSZHJ/e93YXEX+/vIc1PY/WAOkkQ zuul-build-sshkey
2025-10-04 00:20:24.670260 | controller -> localhost | The key's randomart image is:
2025-10-04 00:20:24.670301 | controller -> localhost | +---[RSA 2048]----+
2025-10-04 00:20:24.670339 | controller -> localhost | |..+              |
2025-10-04 00:20:24.670378 | controller -> localhost | | =..      E    . |
2025-10-04 00:20:24.670414 | controller -> localhost | | .= o o ..      o|
2025-10-04 00:20:24.670450 | controller -> localhost | |.= * o = ... . o |
2025-10-04 00:20:24.670486 | controller -> localhost | |o = + * S. .o .oo|
2025-10-04 00:20:24.670545 | controller -> localhost | | . . + *  oo. + =|
2025-10-04 00:20:24.670590 | controller -> localhost | |    . +   ...+ .+|
2025-10-04 00:20:24.670631 | controller -> localhost | |       . . . .o+o|
2025-10-04 00:20:24.670669 | controller -> localhost | |        . .   oo+|
2025-10-04 00:20:24.670748 | controller -> localhost | +----[SHA256]-----+
2025-10-04 00:20:24.670897 | controller -> localhost | ok: Runtime: 0:00:00.149631
2025-10-04 00:20:24.684010 | 
2025-10-04 00:20:24.684235 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-04 00:20:24.732001 | controller | ok
2025-10-04 00:20:24.747411 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-04 00:20:24.761001 | 
2025-10-04 00:20:24.761108 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-04 00:20:24.797625 | controller | skipping: Conditional result was False
2025-10-04 00:20:24.808759 | 
2025-10-04 00:20:24.808880 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-04 00:20:25.463166 | controller | changed
2025-10-04 00:20:25.477880 | 
2025-10-04 00:20:25.478057 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-04 00:20:25.847284 | controller | ok
2025-10-04 00:20:25.863309 | 
2025-10-04 00:20:25.863594 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-04 00:20:27.191323 | controller | changed
2025-10-04 00:20:27.197293 | 
2025-10-04 00:20:27.197391 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-04 00:20:28.519873 | controller | changed
2025-10-04 00:20:28.532223 | 
2025-10-04 00:20:28.532386 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-04 00:20:28.570261 | controller | skipping: Conditional result was False
2025-10-04 00:20:28.586539 | 
2025-10-04 00:20:28.586818 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-04 00:20:29.025074 | controller -> localhost | changed
2025-10-04 00:20:29.036524 | 
2025-10-04 00:20:29.036600 | TASK [add-build-sshkey : Add back temp key]
2025-10-04 00:20:29.367799 | controller -> localhost | Identity added: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_rsa (zuul-build-sshkey)
2025-10-04 00:20:29.368181 | controller -> localhost | ok: Runtime: 0:00:00.010107
2025-10-04 00:20:29.385080 | 
2025-10-04 00:20:29.385246 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-04 00:20:29.931435 | controller | ok
2025-10-04 00:20:29.943249 | 
2025-10-04 00:20:29.943434 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-04 00:20:29.982461 | controller | skipping: Conditional result was False
2025-10-04 00:20:30.010956 | 
2025-10-04 00:20:30.011195 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-04 00:20:30.052587 | controller | ok
2025-10-04 00:20:30.084803 | 
2025-10-04 00:20:30.084974 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-04 00:20:30.375714 | controller -> localhost | ok
2025-10-04 00:20:30.389492 | 
2025-10-04 00:20:30.389669 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-04 00:20:30.430450 | controller | ok
2025-10-04 00:20:30.453804 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-04 00:20:30.462859 | 
2025-10-04 00:20:30.463011 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-04 00:20:30.795703 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-04 00:20:30.796096 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_ecdsa.
2025-10-04 00:20:30.796139 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_ecdsa.pub.
2025-10-04 00:20:30.796186 | controller -> localhost | The key fingerprint is:
2025-10-04 00:20:30.796216 | controller -> localhost | SHA256:UDiYAOXqg1ryAoGvwzX+o2RZDPyyIkkLiUG8e1WBjAk zuul-build-sshkey
2025-10-04 00:20:30.796243 | controller -> localhost | The key's randomart image is:
2025-10-04 00:20:30.796270 | controller -> localhost | +---[ECDSA 521]---+
2025-10-04 00:20:30.796296 | controller -> localhost | |oE+.+o.oo        |
2025-10-04 00:20:30.796322 | controller -> localhost | |.o.ooooo         |
2025-10-04 00:20:30.796348 | controller -> localhost | |o oo  o.         |
2025-10-04 00:20:30.796374 | controller -> localhost | |+=  +. .         |
2025-10-04 00:20:30.796399 | controller -> localhost | |=+...+  S        |
2025-10-04 00:20:30.796425 | controller -> localhost | |*oo+=            |
2025-10-04 00:20:30.796450 | controller -> localhost | |B*==.            |
2025-10-04 00:20:30.796475 | controller -> localhost | |*==. .           |
2025-10-04 00:20:30.796500 | controller -> localhost | |.o..o..          |
2025-10-04 00:20:30.796525 | controller -> localhost | +----[SHA256]-----+
2025-10-04 00:20:30.796606 | controller -> localhost | ok: Runtime: 0:00:00.015254
2025-10-04 00:20:30.809034 | 
2025-10-04 00:20:30.809206 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-04 00:20:30.846413 | controller | ok
2025-10-04 00:20:30.858519 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-04 00:20:30.873263 | 
2025-10-04 00:20:30.873382 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-04 00:20:30.899706 | controller | skipping: Conditional result was False
2025-10-04 00:20:30.909586 | 
2025-10-04 00:20:30.909724 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-04 00:20:31.380754 | controller | changed
2025-10-04 00:20:31.390581 | 
2025-10-04 00:20:31.390736 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-04 00:20:31.749540 | controller | ok
2025-10-04 00:20:31.764618 | 
2025-10-04 00:20:31.764922 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-04 00:20:33.076796 | controller | changed
2025-10-04 00:20:33.092102 | 
2025-10-04 00:20:33.092323 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-04 00:20:34.392180 | controller | changed
2025-10-04 00:20:34.405462 | 
2025-10-04 00:20:34.405605 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-04 00:20:34.442801 | controller | skipping: Conditional result was False
2025-10-04 00:20:34.461182 | 
2025-10-04 00:20:34.461421 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-04 00:20:34.766497 | controller -> localhost | changed
2025-10-04 00:20:34.792389 | 
2025-10-04 00:20:34.792593 | TASK [add-build-sshkey : Add back temp key]
2025-10-04 00:20:35.147853 | controller -> localhost | Identity added: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/a5ff2f29cd3d408fbc705fc38942a3ad_id_ecdsa (zuul-build-sshkey)
2025-10-04 00:20:35.148202 | controller -> localhost | ok: Runtime: 0:00:00.015281
2025-10-04 00:20:35.158180 | 
2025-10-04 00:20:35.158299 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-04 00:20:35.535385 | controller | ok
2025-10-04 00:20:35.547649 | 
2025-10-04 00:20:35.547890 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-04 00:20:35.575898 | controller | skipping: Conditional result was False
2025-10-04 00:20:35.603397 | 
2025-10-04 00:20:35.603524 | TASK [include_role : remove-zuul-sshkey]
2025-10-04 00:20:35.628163 | controller | skipping: Conditional result was False
2025-10-04 00:20:35.670568 | 
2025-10-04 00:20:35.670719 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-04 00:20:35.997794 | controller | ok: "logs"
2025-10-04 00:20:35.998048 | controller | ok: All items complete
2025-10-04 00:20:35.998074 | 
2025-10-04 00:20:36.281098 | controller | ok: "artifacts"
2025-10-04 00:20:36.573538 | controller | ok: "docs"
2025-10-04 00:20:36.590281 | 
2025-10-04 00:20:36.590560 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-04 00:20:36.943568 | controller | changed: "logs"
2025-10-04 00:20:37.242339 | controller | changed: "artifacts"
2025-10-04 00:20:37.546041 | controller | changed: "docs"
2025-10-04 00:20:37.611795 | 
2025-10-04 00:20:37.611942 | PLAY RECAP
2025-10-04 00:20:37.612008 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-04 00:20:37.612045 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-04 00:20:37.612072 | 
2025-10-04 00:20:37.766403 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-04 00:20:37.768205 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-04 00:20:38.480732 | 
2025-10-04 00:20:38.480858 | PLAY [all]
2025-10-04 00:20:38.506294 | 
2025-10-04 00:20:38.506434 | TASK [Install binary dependencies]
2025-10-04 00:20:38.580054 | controller | ok
2025-10-04 00:20:38.603837 | 
2025-10-04 00:20:38.603956 | TASK [bindep : Include find tasks]
2025-10-04 00:20:38.634081 | controller | ok
2025-10-04 00:20:38.644097 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-04 00:20:38.652155 | 
2025-10-04 00:20:38.652234 | TASK [bindep : Look for bindep.txt]
2025-10-04 00:20:39.198894 | controller | ok
2025-10-04 00:20:39.213886 | 
2025-10-04 00:20:39.214033 | TASK [bindep : Define bindep_file fact]
2025-10-04 00:20:39.250254 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.264331 | 
2025-10-04 00:20:39.264487 | TASK [bindep : Look for other-requirements.txt]
2025-10-04 00:20:39.582995 | controller | ok
2025-10-04 00:20:39.599382 | 
2025-10-04 00:20:39.599603 | TASK [bindep : Define bindep_file fact]
2025-10-04 00:20:39.638916 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.654063 | 
2025-10-04 00:20:39.654220 | TASK [bindep : Look for bindep fallback file]
2025-10-04 00:20:39.692142 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.700818 | 
2025-10-04 00:20:39.700944 | TASK [bindep : Define bindep_file fact]
2025-10-04 00:20:39.727153 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.736558 | 
2025-10-04 00:20:39.736725 | TASK [bindep : Include bindep tasks]
2025-10-04 00:20:39.776563 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.791379 | 
2025-10-04 00:20:39.791485 | TASK [bindep : Include install tasks]
2025-10-04 00:20:39.836886 | controller | skipping: Conditional result was False
2025-10-04 00:20:39.850956 | 
2025-10-04 00:20:39.851103 | LOOP [bindep : Include package tasks]
2025-10-04 00:20:39.924737 | 
2025-10-04 00:20:39.925042 | TASK [Run test-setup role]
2025-10-04 00:20:39.948954 | controller | ok
2025-10-04 00:20:39.977100 | 
2025-10-04 00:20:39.977246 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-04 00:20:40.288461 | controller | ok
2025-10-04 00:20:40.296799 | 
2025-10-04 00:20:40.296890 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-04 00:20:40.427488 | controller | skipping: Conditional result was False
2025-10-04 00:20:40.481044 | 
2025-10-04 00:20:40.481162 | PLAY RECAP
2025-10-04 00:20:40.481220 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-04 00:20:40.481249 | 
2025-10-04 00:20:40.631072 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-04 00:20:40.632221 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-04 00:20:41.250881 | 
2025-10-04 00:20:41.251023 | PLAY [controller]
2025-10-04 00:20:41.271651 | 
2025-10-04 00:20:41.271808 | TASK [Create the /root directory]
2025-10-04 00:20:42.029056 | controller | ok
2025-10-04 00:20:42.039853 | 
2025-10-04 00:20:42.040049 | TASK [Install glibc-langpack-en]
2025-10-04 00:20:50.215237 | controller | ok: Nothing to do
2025-10-04 00:20:50.227134 | 
2025-10-04 00:20:50.227254 | TASK [Ensure controller directory exists]
2025-10-04 00:20:50.657196 | controller | changed
2025-10-04 00:20:50.663634 | 
2025-10-04 00:20:50.663812 | TASK [Install container runtime]
2025-10-04 00:20:50.715462 | controller | ok
2025-10-04 00:20:50.751065 | 
2025-10-04 00:20:50.751215 | LOOP [ensure-podman : Find distribution installation]
2025-10-04 00:20:50.784660 | controller | ok: "/var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-04 00:20:50.794529 | controller | included: /var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-04 00:20:50.801023 | 
2025-10-04 00:20:50.801099 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-04 00:22:25.534796 | controller | changed
2025-10-04 00:22:25.548893 | 
2025-10-04 00:22:25.549038 | TASK [ensure-podman : Fetch podman version]
2025-10-04 00:22:26.316924 | controller | Client:       Podman Engine
2025-10-04 00:22:26.317006 | controller | Version:      4.6.2
2025-10-04 00:22:26.317037 | controller | API Version:  4.6.2
2025-10-04 00:22:26.317063 | controller | Go Version:   go1.19.12
2025-10-04 00:22:26.317100 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-04 00:22:26.317128 | controller | OS/Arch:      linux/amd64
2025-10-04 00:22:26.691535 | controller | ok: Runtime: 0:00:00.225507
2025-10-04 00:22:26.699988 | 
2025-10-04 00:22:26.700089 | TASK [ensure-podman : Print podman version installed]
2025-10-04 00:22:26.732166 | Podman version: Client:       Podman Engine
2025-10-04 00:22:26.732360 | Version:      4.6.2
2025-10-04 00:22:26.732400 | API Version:  4.6.2
2025-10-04 00:22:26.732430 | Go Version:   go1.19.12
2025-10-04 00:22:26.732457 | Built:        Mon Aug 28 19:38:31 2023
2025-10-04 00:22:26.732488 | OS/Arch:      linux/amd64
2025-10-04 00:22:26.739764 | 
2025-10-04 00:22:26.739847 | TASK [ensure-podman : Validate podman engine]
2025-10-04 00:22:26.874402 | controller | skipping: Conditional result was False
2025-10-04 00:22:26.883628 | 
2025-10-04 00:22:26.883795 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-04 00:22:26.898611 | controller | skipping: Conditional result was False
2025-10-04 00:22:26.925720 | 
2025-10-04 00:22:26.925874 | TASK [Ensure python3.8 is present]
2025-10-04 00:22:26.941024 | controller | skipping: Conditional result was False
2025-10-04 00:22:26.950106 | 
2025-10-04 00:22:26.950202 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-04 00:22:26.982573 | controller | ok
2025-10-04 00:22:27.009904 | 
2025-10-04 00:22:27.010019 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-04 00:22:30.933158 | controller | ok: Nothing to do
2025-10-04 00:22:30.942400 | 
2025-10-04 00:22:30.942536 | TASK [our-ensure-python : Also install python3-devel]
2025-10-04 00:22:44.006137 | controller | changed
2025-10-04 00:22:44.029666 | 
2025-10-04 00:22:44.029893 | TASK [Run ensure-virtualenv role]
2025-10-04 00:22:44.057149 | controller | ok
2025-10-04 00:22:44.094033 | 
2025-10-04 00:22:44.094189 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-04 00:22:44.462017 | controller | /usr/bin/virtualenv
2025-10-04 00:22:44.733820 | controller | ok: Runtime: 0:00:00.004906
2025-10-04 00:22:44.746393 | 
2025-10-04 00:22:44.746569 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-04 00:22:44.780053 | controller | skipping: Conditional result was False
2025-10-04 00:22:44.780609 | controller | ok: All items complete
2025-10-04 00:22:44.780670 | 
2025-10-04 00:22:44.806862 | 
2025-10-04 00:22:44.807083 | TASK [Find the full path of the Python interpreter]
2025-10-04 00:22:45.269434 | controller | /usr/bin/python3
2025-10-04 00:22:45.485388 | controller | ok
2025-10-04 00:22:45.497363 | 
2025-10-04 00:22:45.497547 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-04 00:22:46.916245 | controller | created virtual environment CPython3.11.0.final.0-64 in 737ms
2025-10-04 00:22:46.957468 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-04 00:22:46.957516 | 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-04 00:22:46.957529 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-04 00:22:46.957546 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-04 00:22:47.153917 | controller | changed
2025-10-04 00:22:47.168245 | 
2025-10-04 00:22:47.168382 | TASK [Set selinux package]
2025-10-04 00:22:47.207352 | controller | ok
2025-10-04 00:22:47.219887 | 
2025-10-04 00:22:47.220037 | TASK [Set selinux package (Fedora)]
2025-10-04 00:22:47.278045 | controller | ok
2025-10-04 00:22:47.288886 | 
2025-10-04 00:22:47.289033 | TASK [Install selinux into virtualenv]
2025-10-04 00:22:49.925995 | controller | Collecting selinux-please-lie-to-me
2025-10-04 00:22:50.014379 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-04 00:22:50.547468 | controller | Collecting setuptools<50.0.0
2025-10-04 00:22:50.560716 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-04 00:22:50.680681 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 7.0 MB/s eta 0:00:00
2025-10-04 00:22:50.830352 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-04 00:22:50.830775 | controller |   Attempting uninstall: setuptools
2025-10-04 00:22:50.835670 | controller |     Found existing installation: setuptools 62.6.0
2025-10-04 00:22:50.948237 | controller |     Uninstalling setuptools-62.6.0:
2025-10-04 00:22:50.962581 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-04 00:22:51.716070 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-04 00:22:51.960558 | controller |
2025-10-04 00:22:52.176279 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-04 00:22:52.176332 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-04 00:22:52.514396 | controller | ok: Runtime: 0:00:04.413240
2025-10-04 00:22:52.523878 | 
2025-10-04 00:22:52.524031 | TASK [Install pytest-forked into virtualenv]
2025-10-04 00:22:53.737461 | controller | Collecting pytest-forked
2025-10-04 00:22:53.821991 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-04 00:22:53.879443 | controller | Collecting py
2025-10-04 00:22:53.891647 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-04 00:22:53.927516 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.3 MB/s eta 0:00:00
2025-10-04 00:22:54.100647 | controller | Collecting pytest>=3.10
2025-10-04 00:22:54.112767 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-04 00:22:54.170228 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 6.7 MB/s eta 0:00:00
2025-10-04 00:22:54.226706 | controller | Collecting iniconfig>=1
2025-10-04 00:22:54.238960 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-04 00:22:54.307679 | controller | Collecting packaging>=20
2025-10-04 00:22:54.319748 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-04 00:22:54.331735 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.7 MB/s eta 0:00:00
2025-10-04 00:22:54.380055 | controller | Collecting pluggy<2,>=1.5
2025-10-04 00:22:54.391795 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-04 00:22:54.466383 | controller | Collecting pygments>=2.7.2
2025-10-04 00:22:54.477887 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-04 00:22:54.594612 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 10.7 MB/s eta 0:00:00
2025-10-04 00:22:54.725663 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-04 00:22:57.006345 | 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-04 00:22:57.022297 | controller |
2025-10-04 00:22:57.202824 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-04 00:22:57.202868 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-04 00:22:57.678340 | controller | ok: Runtime: 0:00:04.193819
2025-10-04 00:22:57.691028 | 
2025-10-04 00:22:57.691227 | TASK [Update pip]
2025-10-04 00:22:58.815743 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-04 00:22:59.075471 | controller | Collecting pip
2025-10-04 00:22:59.173520 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-04 00:22:59.335390 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 11.1 MB/s eta 0:00:00
2025-10-04 00:22:59.484381 | controller | Installing collected packages: pip
2025-10-04 00:22:59.484800 | controller |   Attempting uninstall: pip
2025-10-04 00:22:59.489388 | controller |     Found existing installation: pip 22.2.2
2025-10-04 00:22:59.747453 | controller |     Uninstalling pip-22.2.2:
2025-10-04 00:22:59.777165 | controller |       Successfully uninstalled pip-22.2.2
2025-10-04 00:23:01.541681 | controller | Successfully installed pip-25.2
2025-10-04 00:23:01.843412 | controller | ok: Runtime: 0:00:03.529591
2025-10-04 00:23:01.850024 | 
2025-10-04 00:23:01.850140 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-04 00:23:02.407767 | controller | changed
2025-10-04 00:23:02.421266 | 
2025-10-04 00:23:02.421444 | TASK [Install ansible into virtualenv]
2025-10-04 00:23:03.505617 | controller | Processing ./src/github.com/ansible/ansible
2025-10-04 00:23:03.512080 | controller |   Installing build dependencies: started
2025-10-04 00:23:05.371601 | controller |   Installing build dependencies: finished with status 'done'
2025-10-04 00:23:05.372722 | controller |   Getting requirements to build wheel: started
2025-10-04 00:23:06.890750 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-04 00:23:07.800279 | controller |   Preparing metadata (pyproject.toml): started
2025-10-04 00:23:07.800335 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-04 00:23:07.803562 | 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-04 00:23:07.808316 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-04 00:23:08.086458 | controller | ERROR
2025-10-04 00:23:08.086764 | controller | {
2025-10-04 00:23:08.086832 | controller |   "delta": "0:00:05.077223",
2025-10-04 00:23:08.086876 | controller |   "end": "2025-10-04 00:23:07.951775",
2025-10-04 00:23:08.086914 | controller |   "msg": "non-zero return code",
2025-10-04 00:23:08.086966 | controller |   "rc": 1,
2025-10-04 00:23:08.087003 | controller |   "start": "2025-10-04 00:23:02.874552"
2025-10-04 00:23:08.087038 | controller | }
failure
2025-10-04 00:23:08.089985 | 
2025-10-04 00:23:08.090082 | PLAY RECAP
2025-10-04 00:23:08.090164 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-04 00:23:08.090238 | 
2025-10-04 00:23:08.226486 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-04 00:23:08.227846 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-04 00:23:08.866927 | 
2025-10-04 00:23:08.867052 | PLAY [all]
2025-10-04 00:23:08.889426 | 
2025-10-04 00:23:08.889590 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-04 00:23:09.675629 | controller | changed: non-zero return code
2025-10-04 00:23:09.688451 | 
2025-10-04 00:23:09.688632 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-04 00:23:09.717329 | controller | skipping: Conditional result was False
2025-10-04 00:23:09.731191 | 
2025-10-04 00:23:09.731385 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-04 00:23:09.783620 | 
2025-10-04 00:23:09.783943 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-04 00:23:09.824864 | 
2025-10-04 00:23:09.825183 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-04 00:23:09.852871 | controller | skipping: Conditional result was False
2025-10-04 00:23:09.865857 | 
2025-10-04 00:23:09.866009 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-04 00:23:09.907456 | 
2025-10-04 00:23:09.907763 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-04 00:23:09.934993 | controller | skipping: Conditional result was False
2025-10-04 00:23:09.947115 | 
2025-10-04 00:23:09.947258 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-04 00:23:09.974038 | controller | skipping: Conditional result was False
2025-10-04 00:23:09.986377 | 
2025-10-04 00:23:09.986520 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-04 00:23:10.013742 | controller | skipping: Conditional result was False
2025-10-04 00:23:10.059979 | 
2025-10-04 00:23:10.060114 | PLAY RECAP
2025-10-04 00:23:10.060172 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-04 00:23:10.060201 | 
2025-10-04 00:23:10.162402 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-04 00:23:10.163267 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-04 00:23:10.734888 | 
2025-10-04 00:23:10.735006 | PLAY [all:!appliance*]
2025-10-04 00:23:10.756752 | 
2025-10-04 00:23:10.756878 | TASK [unregister the node]
2025-10-04 00:23:10.885193 | controller | skipping: Conditional result was False
2025-10-04 00:23:10.897430 | 
2025-10-04 00:23:10.897589 | TASK [include_role : fetch-output]
2025-10-04 00:23:10.936544 | controller | ok
2025-10-04 00:23:10.970790 | 
2025-10-04 00:23:10.970881 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-04 00:23:11.036881 | controller | skipping: Conditional result was False
2025-10-04 00:23:11.049493 | 
2025-10-04 00:23:11.049636 | TASK [fetch-output : Set log path for single node]
2025-10-04 00:23:11.098220 | controller | ok
2025-10-04 00:23:11.110834 | 
2025-10-04 00:23:11.110978 | LOOP [fetch-output : Ensure local output dirs]
2025-10-04 00:23:11.563532 | controller -> localhost | ok: "/var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/logs"
2025-10-04 00:23:11.831365 | controller -> localhost | changed: "/var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/artifacts"
2025-10-04 00:23:12.096825 | controller -> localhost | changed: "/var/lib/zuul/builds/a5ff2f29cd3d408fbc705fc38942a3ad/work/docs"
2025-10-04 00:23:12.115641 | 
2025-10-04 00:23:12.115746 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-04 00:23:13.328260 | controller | changed:
2025-10-04 00:23:13.328453 | controller | .d..t...... ./
2025-10-04 00:23:13.328482 | controller | cd+++++++++ controller/
2025-10-04 00:23:13.328515 | controller | changed: All items complete
2025-10-04 00:23:13.328536 | 
2025-10-04 00:23:14.390615 | controller | changed: .d..t...... ./
2025-10-04 00:23:15.456047 | controller | changed: .d..t...... ./
2025-10-04 00:23:15.473763 | 
2025-10-04 00:23:15.473893 | TASK [include_role : fetch-output-openshift]
2025-10-04 00:23:15.489173 | controller | skipping: Conditional result was False
2025-10-04 00:23:15.497341 | 
2025-10-04 00:23:15.497469 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-04 00:23:15.524474 | controller | skipping: Conditional result was False
2025-10-04 00:23:15.533619 | controller | skipping: Conditional result was False
2025-10-04 00:23:15.585085 | 
2025-10-04 00:23:15.585206 | PLAY [localhost]
2025-10-04 00:23:15.600976 | 
2025-10-04 00:23:15.601111 | TASK [Run Zuul manifest role]
2025-10-04 00:23:15.619883 | localhost | ok
2025-10-04 00:23:15.634639 | 
2025-10-04 00:23:15.634756 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-04 00:23:16.066098 | localhost | changed
2025-10-04 00:23:16.070945 | 
2025-10-04 00:23:16.071015 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-04 00:23:16.120815 | localhost | ok
2025-10-04 00:23:16.128942 | 
2025-10-04 00:23:16.129006 | TASK [Set zuul-log-path fact]
2025-10-04 00:23:16.157748 | localhost | ok
2025-10-04 00:23:16.171199 | 
2025-10-04 00:23:16.171272 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-04 00:23:16.200253 | localhost | ok
2025-10-04 00:23:16.209189 | 
2025-10-04 00:23:16.209253 | LOOP [Run upload-logs-swift role]
2025-10-04 00:23:16.246026 | localhost | Output suppressed because no_log was given
2025-10-04 00:23:16.271640 | 
2025-10-04 00:23:16.271763 | TASK [Set zuul-log-path fact]
2025-10-04 00:23:16.296040 | localhost | skipping: Conditional result was False
2025-10-04 00:23:16.301064 | 
2025-10-04 00:23:16.301130 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-04 00:23:16.753618 | localhost -> localhost | ok: Runtime: 0:00:00.009259
2025-10-04 00:23:16.761147 | 
2025-10-04 00:23:16.761229 | TASK [upload-logs-swift : Upload logs to swift]