2025-11-06 00:17:58.273628 | Job console starting...
2025-11-06 00:17:58.285973 | Updating repositories
2025-11-06 00:17:58.435552 | Preparing job workspace
2025-11-06 00:18:02.288128 | Running Ansible setup...
2025-11-06 00:18:08.795633 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-06 00:18:09.422338 | 
2025-11-06 00:18:09.422491 | PLAY [localhost]
2025-11-06 00:18:09.432306 | 
2025-11-06 00:18:09.432423 | TASK [Gathering Facts]
2025-11-06 00:18:10.398422 | localhost | ok
2025-11-06 00:18:10.418044 | 
2025-11-06 00:18:10.418227 | TASK [Setup log path fact]
2025-11-06 00:18:10.437637 | localhost | ok
2025-11-06 00:18:10.454866 | 
2025-11-06 00:18:10.455002 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-06 00:18:10.495070 | localhost | ok
2025-11-06 00:18:10.503417 | 
2025-11-06 00:18:10.503524 | TASK [emit-job-header : Print job information]
2025-11-06 00:18:10.553044 | # Job Information
2025-11-06 00:18:10.553228 | Ansible Version: 2.15.12
2025-11-06 00:18:10.553265 | Job: ansible-test-sanity-docker-devel
2025-11-06 00:18:10.553287 | Pipeline: periodic
2025-11-06 00:18:10.553305 | Executor: ze03.softwarefactory-project.io
2025-11-06 00:18:10.553324 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-06 00:18:10.553346 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/516/ansible/516cb0fac59f47238b1e13a4a01fc998/
2025-11-06 00:18:10.553366 | Event ID: 06b8e19d0def49e3b59e004861f83875
2025-11-06 00:18:10.557133 | 
2025-11-06 00:18:10.557198 | LOOP [emit-job-header : Print node information]
2025-11-06 00:18:10.690072 | localhost | ok:
2025-11-06 00:18:10.690279 | localhost | # Node Information
2025-11-06 00:18:10.690307 | localhost | Inventory Hostname: controller
2025-11-06 00:18:10.690327 | localhost | Hostname: ip-172-16-211-165
2025-11-06 00:18:10.690346 | localhost | Username: zuul-worker
2025-11-06 00:18:10.690366 | localhost | Distro: Fedora 37
2025-11-06 00:18:10.690384 | localhost | Provider: ansible-us-east-2
2025-11-06 00:18:10.690401 | localhost | Region: us-east-2
2025-11-06 00:18:10.690418 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-06 00:18:10.690434 | localhost | Product Name: t3.small
2025-11-06 00:18:10.690450 | localhost | Interface IP: 3.20.226.214
2025-11-06 00:18:10.705973 | 
2025-11-06 00:18:10.706141 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-06 00:18:11.140329 | localhost -> localhost | changed
2025-11-06 00:18:11.146028 | 
2025-11-06 00:18:11.146114 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-06 00:18:12.061636 | localhost -> localhost | changed
2025-11-06 00:18:12.103708 | 
2025-11-06 00:18:12.103827 | PLAY [all:!appliance*]
2025-11-06 00:18:12.130228 | 
2025-11-06 00:18:12.130374 | TASK [include_role : start-zuul-console]
2025-11-06 00:18:12.150815 | controller | ok
2025-11-06 00:18:12.168089 | 
2025-11-06 00:18:12.168242 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-06 00:18:12.842747 | controller | ok
2025-11-06 00:18:12.857856 | 
2025-11-06 00:18:12.857984 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-06 00:18:14.410680 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-06 00:18:14.418608 | 
2025-11-06 00:18:14.418718 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-06 00:18:14.554671 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.561026 | 
2025-11-06 00:18:14.561138 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-06 00:18:14.585345 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.591631 | 
2025-11-06 00:18:14.591743 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-06 00:18:14.605890 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.613039 | 
2025-11-06 00:18:14.613159 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-06 00:18:14.637613 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.644490 | 
2025-11-06 00:18:14.644601 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-06 00:18:14.659011 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.668300 | 
2025-11-06 00:18:14.668423 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-06 00:18:14.693685 | controller | skipping: Conditional result was False
2025-11-06 00:18:14.711561 | 
2025-11-06 00:18:14.711702 | TASK [Disable Fedora Modular]
2025-11-06 00:18:15.548044 | controller | changed
2025-11-06 00:18:15.565986 | 
2025-11-06 00:18:15.566151 | TASK [Enable EPEL]
2025-11-06 00:18:15.584120 | controller | skipping: Conditional result was False
2025-11-06 00:18:15.598344 | 
2025-11-06 00:18:15.598505 | TASK [Register the RHEL node]
2025-11-06 00:18:15.768714 | 
2025-11-06 00:18:15.768909 | TASK [Show the subscription-manager status]
2025-11-06 00:18:15.903894 | controller | skipping: Conditional result was False
2025-11-06 00:18:15.946660 | 
2025-11-06 00:18:15.946815 | TASK [Enable EPEL on RHEL]
2025-11-06 00:18:16.087205 | controller | skipping: Conditional result was False
2025-11-06 00:18:16.095639 | 
2025-11-06 00:18:16.095745 | TASK [Install git and tox]
2025-11-06 00:19:57.829205 | controller | changed
2025-11-06 00:19:57.842144 | 
2025-11-06 00:19:57.842306 | TASK [include_role : prepare-workspace]
2025-11-06 00:19:57.876514 | controller | ok
2025-11-06 00:19:57.909825 | 
2025-11-06 00:19:57.909989 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-06 00:19:58.481074 | controller | ok
2025-11-06 00:19:58.492353 | 
2025-11-06 00:19:58.492553 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-06 00:20:11.696785 | controller | Output suppressed because no_log was given
2025-11-06 00:20:11.711458 | 
2025-11-06 00:20:11.711567 | TASK [include_role : prepare-workspace-openshift]
2025-11-06 00:20:11.731604 | controller | skipping: Conditional result was False
2025-11-06 00:20:11.759998 | 
2025-11-06 00:20:11.760080 | PLAY [all:!appliance]
2025-11-06 00:20:11.782813 | 
2025-11-06 00:20:11.782957 | TASK [Run add-build-sshkey role (RSA)]
2025-11-06 00:20:11.814315 | controller | ok
2025-11-06 00:20:11.863645 | 
2025-11-06 00:20:11.863786 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-06 00:20:12.124273 | controller -> localhost | ok
2025-11-06 00:20:12.142169 | 
2025-11-06 00:20:12.142347 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-06 00:20:12.172062 | controller | ok
2025-11-06 00:20:12.198963 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-06 00:20:12.208788 | 
2025-11-06 00:20:12.208939 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-06 00:20:12.702626 | controller -> localhost | Generating public/private rsa key pair.
2025-11-06 00:20:12.702838 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_rsa.
2025-11-06 00:20:12.702877 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_rsa.pub.
2025-11-06 00:20:12.702901 | controller -> localhost | The key fingerprint is:
2025-11-06 00:20:12.702923 | controller -> localhost | SHA256:8XgLluW5laY1Ka+EtnAqgyUmBr89CukrmnhczeGt2kI zuul-build-sshkey
2025-11-06 00:20:12.702946 | controller -> localhost | The key's randomart image is:
2025-11-06 00:20:12.702966 | controller -> localhost | +---[RSA 2048]----+
2025-11-06 00:20:12.702985 | controller -> localhost | |                 |
2025-11-06 00:20:12.703004 | controller -> localhost | |                 |
2025-11-06 00:20:12.703023 | controller -> localhost | |        . .      |
2025-11-06 00:20:12.703043 | controller -> localhost | |.     .  B . o   |
2025-11-06 00:20:12.703061 | controller -> localhost | |..   + oS * B    |
2025-11-06 00:20:12.703089 | controller -> localhost | |.o+ E +..+ X .   |
2025-11-06 00:20:12.703114 | controller -> localhost | |++ O  ..+ = .    |
2025-11-06 00:20:12.703135 | controller -> localhost | |+o= *..= o .     |
2025-11-06 00:20:12.703155 | controller -> localhost | |*+o..*o . .      |
2025-11-06 00:20:12.703175 | controller -> localhost | +----[SHA256]-----+
2025-11-06 00:20:12.703218 | controller -> localhost | ok: Runtime: 0:00:00.082494
2025-11-06 00:20:12.711560 | 
2025-11-06 00:20:12.711697 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-06 00:20:12.741926 | controller | ok
2025-11-06 00:20:12.752974 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-06 00:20:12.762409 | 
2025-11-06 00:20:12.762509 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-06 00:20:12.776170 | controller | skipping: Conditional result was False
2025-11-06 00:20:12.783464 | 
2025-11-06 00:20:12.783571 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-06 00:20:13.432705 | controller | changed
2025-11-06 00:20:13.445992 | 
2025-11-06 00:20:13.446154 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-06 00:20:13.852470 | controller | ok
2025-11-06 00:20:13.866954 | 
2025-11-06 00:20:13.867143 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-06 00:20:15.428210 | controller | changed
2025-11-06 00:20:15.433975 | 
2025-11-06 00:20:15.434044 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-06 00:20:16.976490 | controller | changed
2025-11-06 00:20:16.991974 | 
2025-11-06 00:20:16.993321 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-06 00:20:17.038789 | controller | skipping: Conditional result was False
2025-11-06 00:20:17.050897 | 
2025-11-06 00:20:17.051017 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-06 00:20:17.419260 | controller -> localhost | changed
2025-11-06 00:20:17.433179 | 
2025-11-06 00:20:17.433272 | TASK [add-build-sshkey : Add back temp key]
2025-11-06 00:20:17.711374 | controller -> localhost | Identity added: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_rsa (zuul-build-sshkey)
2025-11-06 00:20:17.711625 | controller -> localhost | ok: Runtime: 0:00:00.007899
2025-11-06 00:20:17.718847 | 
2025-11-06 00:20:17.718922 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-06 00:20:18.261125 | controller | ok
2025-11-06 00:20:18.269922 | 
2025-11-06 00:20:18.270009 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-06 00:20:18.304923 | controller | skipping: Conditional result was False
2025-11-06 00:20:18.321137 | 
2025-11-06 00:20:18.321233 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-06 00:20:18.355201 | controller | ok
2025-11-06 00:20:18.375375 | 
2025-11-06 00:20:18.375513 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-06 00:20:18.637014 | controller -> localhost | ok
2025-11-06 00:20:18.643028 | 
2025-11-06 00:20:18.643092 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-06 00:20:18.673269 | controller | ok
2025-11-06 00:20:18.684172 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-06 00:20:18.690604 | 
2025-11-06 00:20:18.690672 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-06 00:20:18.947771 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-06 00:20:18.948011 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_ecdsa.
2025-11-06 00:20:18.948042 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_ecdsa.pub.
2025-11-06 00:20:18.948071 | controller -> localhost | The key fingerprint is:
2025-11-06 00:20:18.948091 | controller -> localhost | SHA256:bfEzmHlaQFTjmnnsPvPLQwakbINEnY9n8syhvnenD9E zuul-build-sshkey
2025-11-06 00:20:18.948110 | controller -> localhost | The key's randomart image is:
2025-11-06 00:20:18.948129 | controller -> localhost | +---[ECDSA 521]---+
2025-11-06 00:20:18.948146 | controller -> localhost | |       ..oooo    |
2025-11-06 00:20:18.948164 | controller -> localhost | |        ..o...   |
2025-11-06 00:20:18.948181 | controller -> localhost | |       . oo=.    |
2025-11-06 00:20:18.948198 | controller -> localhost | |        ..B%*  . |
2025-11-06 00:20:18.948215 | controller -> localhost | |        S.XXOo. E|
2025-11-06 00:20:18.948232 | controller -> localhost | |         ..*+oo. |
2025-11-06 00:20:18.948249 | controller -> localhost | |         .. .o.  |
2025-11-06 00:20:18.948265 | controller -> localhost | |          ..+.o..|
2025-11-06 00:20:18.948282 | controller -> localhost | |          .o.==*.|
2025-11-06 00:20:18.948300 | controller -> localhost | +----[SHA256]-----+
2025-11-06 00:20:18.948360 | controller -> localhost | ok: Runtime: 0:00:00.017648
2025-11-06 00:20:18.954935 | 
2025-11-06 00:20:18.955063 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-06 00:20:18.983201 | controller | ok
2025-11-06 00:20:18.990380 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-06 00:20:18.999950 | 
2025-11-06 00:20:19.000013 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-06 00:20:19.023587 | controller | skipping: Conditional result was False
2025-11-06 00:20:19.030000 | 
2025-11-06 00:20:19.030066 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-06 00:20:19.523341 | controller | changed
2025-11-06 00:20:19.536838 | 
2025-11-06 00:20:19.536974 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-06 00:20:19.892504 | controller | ok
2025-11-06 00:20:19.904285 | 
2025-11-06 00:20:19.904394 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-06 00:20:21.225689 | controller | changed
2025-11-06 00:20:21.231378 | 
2025-11-06 00:20:21.231458 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-06 00:20:22.526419 | controller | changed
2025-11-06 00:20:22.533011 | 
2025-11-06 00:20:22.533090 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-06 00:20:22.546835 | controller | skipping: Conditional result was False
2025-11-06 00:20:22.554176 | 
2025-11-06 00:20:22.554274 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-06 00:20:22.782937 | controller -> localhost | changed
2025-11-06 00:20:22.809948 | 
2025-11-06 00:20:22.810083 | TASK [add-build-sshkey : Add back temp key]
2025-11-06 00:20:23.099935 | controller -> localhost | Identity added: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/516cb0fac59f47238b1e13a4a01fc998_id_ecdsa (zuul-build-sshkey)
2025-11-06 00:20:23.100144 | controller -> localhost | ok: Runtime: 0:00:00.008257
2025-11-06 00:20:23.107722 | 
2025-11-06 00:20:23.107830 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-06 00:20:23.456400 | controller | ok
2025-11-06 00:20:23.465242 | 
2025-11-06 00:20:23.465373 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-06 00:20:23.490239 | controller | skipping: Conditional result was False
2025-11-06 00:20:23.502603 | 
2025-11-06 00:20:23.502710 | TASK [include_role : remove-zuul-sshkey]
2025-11-06 00:20:23.516369 | controller | skipping: Conditional result was False
2025-11-06 00:20:23.530320 | 
2025-11-06 00:20:23.530427 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-06 00:20:24.090029 | controller | ok: "logs"
2025-11-06 00:20:24.090267 | controller | ok: All items complete
2025-11-06 00:20:24.090296 | 
2025-11-06 00:20:24.381990 | controller | ok: "artifacts"
2025-11-06 00:20:24.790118 | controller | ok: "docs"
2025-11-06 00:20:24.804918 | 
2025-11-06 00:20:24.805140 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-06 00:20:25.154943 | controller | changed: "logs"
2025-11-06 00:20:25.447475 | controller | changed: "artifacts"
2025-11-06 00:20:25.744840 | controller | changed: "docs"
2025-11-06 00:20:25.792884 | 
2025-11-06 00:20:25.793023 | PLAY RECAP
2025-11-06 00:20:25.793185 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-06 00:20:25.793252 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-06 00:20:25.793294 | 
2025-11-06 00:20:25.928682 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-06 00:20:25.929611 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-06 00:20:26.564631 | 
2025-11-06 00:20:26.564755 | PLAY [all]
2025-11-06 00:20:26.596445 | 
2025-11-06 00:20:26.596573 | TASK [Install binary dependencies]
2025-11-06 00:20:26.667474 | controller | ok
2025-11-06 00:20:26.704321 | 
2025-11-06 00:20:26.704455 | TASK [bindep : Include find tasks]
2025-11-06 00:20:26.739470 | controller | ok
2025-11-06 00:20:26.750149 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-06 00:20:26.756403 | 
2025-11-06 00:20:26.756500 | TASK [bindep : Look for bindep.txt]
2025-11-06 00:20:27.297400 | controller | ok
2025-11-06 00:20:27.306070 | 
2025-11-06 00:20:27.306194 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:20:27.320433 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.327306 | 
2025-11-06 00:20:27.327445 | TASK [bindep : Look for other-requirements.txt]
2025-11-06 00:20:27.655526 | controller | ok
2025-11-06 00:20:27.661080 | 
2025-11-06 00:20:27.661160 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:20:27.685788 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.693077 | 
2025-11-06 00:20:27.693190 | TASK [bindep : Look for bindep fallback file]
2025-11-06 00:20:27.727847 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.735752 | 
2025-11-06 00:20:27.736002 | TASK [bindep : Define bindep_file fact]
2025-11-06 00:20:27.761286 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.769486 | 
2025-11-06 00:20:27.769613 | TASK [bindep : Include bindep tasks]
2025-11-06 00:20:27.794647 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.804521 | 
2025-11-06 00:20:27.804641 | TASK [bindep : Include install tasks]
2025-11-06 00:20:27.830348 | controller | skipping: Conditional result was False
2025-11-06 00:20:27.838583 | 
2025-11-06 00:20:27.838708 | LOOP [bindep : Include package tasks]
2025-11-06 00:20:27.895515 | 
2025-11-06 00:20:27.895682 | TASK [Run test-setup role]
2025-11-06 00:20:27.915496 | controller | ok
2025-11-06 00:20:27.934333 | 
2025-11-06 00:20:27.934445 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-06 00:20:28.267416 | controller | ok
2025-11-06 00:20:28.279408 | 
2025-11-06 00:20:28.279576 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-06 00:20:28.435066 | controller | skipping: Conditional result was False
2025-11-06 00:20:28.469964 | 
2025-11-06 00:20:28.470068 | PLAY RECAP
2025-11-06 00:20:28.470121 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-06 00:20:28.470150 | 
2025-11-06 00:20:28.606133 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-06 00:20:28.607137 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-06 00:20:29.262284 | 
2025-11-06 00:20:29.262417 | PLAY [controller]
2025-11-06 00:20:29.282820 | 
2025-11-06 00:20:29.282954 | TASK [Create the /root directory]
2025-11-06 00:20:30.049221 | controller | ok
2025-11-06 00:20:30.071048 | 
2025-11-06 00:20:30.071210 | TASK [Install glibc-langpack-en]
2025-11-06 00:20:38.103560 | controller | ok: Nothing to do
2025-11-06 00:20:38.112584 | 
2025-11-06 00:20:38.112743 | TASK [Ensure controller directory exists]
2025-11-06 00:20:38.615471 | controller | changed
2025-11-06 00:20:38.621006 | 
2025-11-06 00:20:38.621072 | TASK [Install container runtime]
2025-11-06 00:20:38.705433 | controller | ok
2025-11-06 00:20:38.768655 | 
2025-11-06 00:20:38.768812 | LOOP [ensure-podman : Find distribution installation]
2025-11-06 00:20:38.793818 | controller | ok: "/var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-06 00:20:38.818660 | controller | included: /var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-06 00:20:38.825886 | 
2025-11-06 00:20:38.825963 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-06 00:22:02.824547 | controller | changed
2025-11-06 00:22:02.838852 | 
2025-11-06 00:22:02.839052 | TASK [ensure-podman : Fetch podman version]
2025-11-06 00:22:03.679291 | controller | Client:       Podman Engine
2025-11-06 00:22:03.707124 | controller | Version:      4.6.2
2025-11-06 00:22:03.707180 | controller | API Version:  4.6.2
2025-11-06 00:22:03.707188 | controller | Go Version:   go1.19.12
2025-11-06 00:22:03.707207 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-06 00:22:03.707220 | controller | OS/Arch:      linux/amd64
2025-11-06 00:22:03.998030 | controller | ok: Runtime: 0:00:00.282155
2025-11-06 00:22:04.005107 | 
2025-11-06 00:22:04.005215 | TASK [ensure-podman : Print podman version installed]
2025-11-06 00:22:04.035088 | Podman version: Client:       Podman Engine
2025-11-06 00:22:04.035250 | Version:      4.6.2
2025-11-06 00:22:04.035282 | API Version:  4.6.2
2025-11-06 00:22:04.035306 | Go Version:   go1.19.12
2025-11-06 00:22:04.035326 | Built:        Mon Aug 28 19:38:31 2023
2025-11-06 00:22:04.035348 | OS/Arch:      linux/amd64
2025-11-06 00:22:04.041015 | 
2025-11-06 00:22:04.041113 | TASK [ensure-podman : Validate podman engine]
2025-11-06 00:22:04.184912 | controller | skipping: Conditional result was False
2025-11-06 00:22:04.191488 | 
2025-11-06 00:22:04.191570 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-06 00:22:04.205224 | controller | skipping: Conditional result was False
2025-11-06 00:22:04.216920 | 
2025-11-06 00:22:04.216993 | TASK [Ensure python3.8 is present]
2025-11-06 00:22:04.241117 | controller | skipping: Conditional result was False
2025-11-06 00:22:04.248437 | 
2025-11-06 00:22:04.248524 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-06 00:22:04.279206 | controller | ok
2025-11-06 00:22:04.299078 | 
2025-11-06 00:22:04.299198 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-06 00:22:08.206049 | controller | ok: Nothing to do
2025-11-06 00:22:08.215345 | 
2025-11-06 00:22:08.215519 | TASK [our-ensure-python : Also install python3-devel]
2025-11-06 00:22:22.305365 | controller | changed
2025-11-06 00:22:22.316501 | 
2025-11-06 00:22:22.316631 | TASK [Run ensure-virtualenv role]
2025-11-06 00:22:22.336472 | controller | ok
2025-11-06 00:22:22.358698 | 
2025-11-06 00:22:22.358838 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-06 00:22:22.774598 | controller | /usr/bin/virtualenv
2025-11-06 00:22:23.026493 | controller | ok: Runtime: 0:00:00.004634
2025-11-06 00:22:23.032575 | 
2025-11-06 00:22:23.032668 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-06 00:22:23.052125 | controller | skipping: Conditional result was False
2025-11-06 00:22:23.052404 | controller | ok: All items complete
2025-11-06 00:22:23.052432 | 
2025-11-06 00:22:23.071284 | 
2025-11-06 00:22:23.071432 | TASK [Find the full path of the Python interpreter]
2025-11-06 00:22:23.499963 | controller | /usr/bin/python3
2025-11-06 00:22:23.719447 | controller | ok
2025-11-06 00:22:23.725276 | 
2025-11-06 00:22:23.725373 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-06 00:22:25.220123 | controller | created virtual environment CPython3.11.0.final.0-64 in 805ms
2025-11-06 00:22:25.261625 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-06 00:22:25.261704 | 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-06 00:22:25.261720 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-06 00:22:25.261744 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-06 00:22:25.376057 | controller | changed
2025-11-06 00:22:25.385071 | 
2025-11-06 00:22:25.385234 | TASK [Set selinux package]
2025-11-06 00:22:25.419061 | controller | ok
2025-11-06 00:22:25.427470 | 
2025-11-06 00:22:25.427619 | TASK [Set selinux package (Fedora)]
2025-11-06 00:22:25.459288 | controller | ok
2025-11-06 00:22:25.465500 | 
2025-11-06 00:22:25.465587 | TASK [Install selinux into virtualenv]
2025-11-06 00:22:28.070318 | controller | Collecting selinux-please-lie-to-me
2025-11-06 00:22:28.158051 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-06 00:22:28.686192 | controller | Collecting setuptools<50.0.0
2025-11-06 00:22:28.699322 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-06 00:22:28.841197 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 6.0 MB/s eta 0:00:00
2025-11-06 00:22:28.993508 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-06 00:22:28.993941 | controller |   Attempting uninstall: setuptools
2025-11-06 00:22:28.998951 | controller |     Found existing installation: setuptools 62.6.0
2025-11-06 00:22:29.111296 | controller |     Uninstalling setuptools-62.6.0:
2025-11-06 00:22:29.126736 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-06 00:22:29.889029 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-06 00:22:30.094656 | controller |
2025-11-06 00:22:30.313785 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-06 00:22:30.313836 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-06 00:22:30.638860 | controller | ok: Runtime: 0:00:04.374489
2025-11-06 00:22:30.645346 | 
2025-11-06 00:22:30.645441 | TASK [Install pytest-forked into virtualenv]
2025-11-06 00:22:32.038114 | controller | Collecting pytest-forked
2025-11-06 00:22:32.126078 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-06 00:22:32.186741 | controller | Collecting py
2025-11-06 00:22:32.200307 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-06 00:22:32.237753 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.2 MB/s eta 0:00:00
2025-11-06 00:22:32.414139 | controller | Collecting pytest>=3.10
2025-11-06 00:22:32.427587 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-11-06 00:22:32.493297 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 5.8 MB/s eta 0:00:00
2025-11-06 00:22:32.551429 | controller | Collecting iniconfig>=1
2025-11-06 00:22:32.565057 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-06 00:22:32.633917 | controller | Collecting packaging>=20
2025-11-06 00:22:32.647069 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-06 00:22:32.659876 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.2 MB/s eta 0:00:00
2025-11-06 00:22:32.704035 | controller | Collecting pluggy<2,>=1.5
2025-11-06 00:22:32.716783 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-06 00:22:32.790559 | controller | Collecting pygments>=2.7.2
2025-11-06 00:22:32.803970 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-06 00:22:32.933764 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 9.7 MB/s eta 0:00:00
2025-11-06 00:22:33.066814 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-06 00:22:35.339733 | 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-06 00:22:35.355876 | controller |
2025-11-06 00:22:35.546188 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-06 00:22:35.546241 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-06 00:22:35.808864 | controller | ok: Runtime: 0:00:04.233744
2025-11-06 00:22:35.820766 | 
2025-11-06 00:22:35.820914 | TASK [Update pip]
2025-11-06 00:22:37.184861 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-06 00:22:37.462382 | controller | Collecting pip
2025-11-06 00:22:37.561307 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-06 00:22:37.793897 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 7.8 MB/s eta 0:00:00
2025-11-06 00:22:37.947102 | controller | Installing collected packages: pip
2025-11-06 00:22:37.947521 | controller |   Attempting uninstall: pip
2025-11-06 00:22:37.952077 | controller |     Found existing installation: pip 22.2.2
2025-11-06 00:22:38.208978 | controller |     Uninstalling pip-22.2.2:
2025-11-06 00:22:38.239384 | controller |       Successfully uninstalled pip-22.2.2
2025-11-06 00:22:40.021583 | controller | Successfully installed pip-25.3
2025-11-06 00:22:40.475266 | controller | ok: Runtime: 0:00:03.737450
2025-11-06 00:22:40.483349 | 
2025-11-06 00:22:40.483456 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-06 00:22:41.088078 | controller | changed
2025-11-06 00:22:41.096128 | 
2025-11-06 00:22:41.096241 | TASK [Install ansible into virtualenv]
2025-11-06 00:22:42.338887 | controller | Processing ./src/github.com/ansible/ansible
2025-11-06 00:22:42.345254 | controller |   Installing build dependencies: started
2025-11-06 00:22:44.338315 | controller |   Installing build dependencies: finished with status 'done'
2025-11-06 00:22:46.010241 | controller |   Getting requirements to build wheel: started
2025-11-06 00:22:46.010301 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-06 00:22:46.011840 | controller |   Preparing metadata (pyproject.toml): started
2025-11-06 00:22:46.935755 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-06 00:22:46.938865 | 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-06 00:22:46.943779 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-06 00:22:47.235873 | controller | ERROR
2025-11-06 00:22:47.236051 | controller | {
2025-11-06 00:22:47.236083 | controller |   "delta": "0:00:05.465061",
2025-11-06 00:22:47.236103 | controller |   "end": "2025-11-06 00:22:47.088244",
2025-11-06 00:22:47.236122 | controller |   "msg": "non-zero return code",
2025-11-06 00:22:47.236148 | controller |   "rc": 1,
2025-11-06 00:22:47.236165 | controller |   "start": "2025-11-06 00:22:41.623183"
2025-11-06 00:22:47.236182 | controller | }
failure
2025-11-06 00:22:47.237788 | 
2025-11-06 00:22:47.237849 | PLAY RECAP
2025-11-06 00:22:47.237901 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-06 00:22:47.237927 | 
2025-11-06 00:22:47.376490 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-06 00:22:47.377631 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-06 00:22:47.988914 | 
2025-11-06 00:22:47.989041 | PLAY [all]
2025-11-06 00:22:48.015404 | 
2025-11-06 00:22:48.015544 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-06 00:22:48.912073 | controller | changed: non-zero return code
2025-11-06 00:22:48.923228 | 
2025-11-06 00:22:48.923447 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-06 00:22:48.939023 | controller | skipping: Conditional result was False
2025-11-06 00:22:48.946601 | 
2025-11-06 00:22:48.946691 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-06 00:22:48.969037 | 
2025-11-06 00:22:48.969212 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-06 00:22:48.992616 | 
2025-11-06 00:22:48.992878 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-06 00:22:49.011929 | controller | skipping: Conditional result was False
2025-11-06 00:22:49.018915 | 
2025-11-06 00:22:49.019024 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-06 00:22:49.039879 | 
2025-11-06 00:22:49.040047 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-06 00:22:49.053922 | controller | skipping: Conditional result was False
2025-11-06 00:22:49.060193 | 
2025-11-06 00:22:49.060313 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-06 00:22:49.078212 | controller | skipping: Conditional result was False
2025-11-06 00:22:49.085242 | 
2025-11-06 00:22:49.085345 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-06 00:22:49.100852 | controller | skipping: Conditional result was False
2025-11-06 00:22:49.134872 | 
2025-11-06 00:22:49.134988 | PLAY RECAP
2025-11-06 00:22:49.135043 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-06 00:22:49.135065 | 
2025-11-06 00:22:49.262266 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-06 00:22:49.263353 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-06 00:22:49.906661 | 
2025-11-06 00:22:49.906797 | PLAY [all:!appliance*]
2025-11-06 00:22:49.928558 | 
2025-11-06 00:22:49.928686 | TASK [unregister the node]
2025-11-06 00:22:50.070064 | controller | skipping: Conditional result was False
2025-11-06 00:22:50.079333 | 
2025-11-06 00:22:50.079490 | TASK [include_role : fetch-output]
2025-11-06 00:22:50.123636 | controller | ok
2025-11-06 00:22:50.153322 | 
2025-11-06 00:22:50.153458 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-06 00:22:50.220497 | controller | skipping: Conditional result was False
2025-11-06 00:22:50.241597 | 
2025-11-06 00:22:50.241771 | TASK [fetch-output : Set log path for single node]
2025-11-06 00:22:50.272019 | controller | ok
2025-11-06 00:22:50.277893 | 
2025-11-06 00:22:50.277990 | LOOP [fetch-output : Ensure local output dirs]
2025-11-06 00:22:50.686564 | controller -> localhost | ok: "/var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/logs"
2025-11-06 00:22:50.903999 | controller -> localhost | changed: "/var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/artifacts"
2025-11-06 00:22:51.154194 | controller -> localhost | changed: "/var/lib/zuul/builds/516cb0fac59f47238b1e13a4a01fc998/work/docs"
2025-11-06 00:22:51.176007 | 
2025-11-06 00:22:51.176156 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-06 00:22:52.528056 | controller | changed:
2025-11-06 00:22:52.528385 | controller | .d..t...... ./
2025-11-06 00:22:52.528447 | controller | cd+++++++++ controller/
2025-11-06 00:22:52.528525 | controller | changed: All items complete
2025-11-06 00:22:52.528590 | 
2025-11-06 00:22:53.577222 | controller | changed: .d..t...... ./
2025-11-06 00:22:54.655051 | controller | changed: .d..t...... ./
2025-11-06 00:22:54.688483 | 
2025-11-06 00:22:54.688614 | TASK [include_role : fetch-output-openshift]
2025-11-06 00:22:54.702451 | controller | skipping: Conditional result was False
2025-11-06 00:22:54.709818 | 
2025-11-06 00:22:54.709914 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-06 00:22:54.740463 | controller | skipping: Conditional result was False
2025-11-06 00:22:54.750581 | controller | skipping: Conditional result was False
2025-11-06 00:22:54.783642 | 
2025-11-06 00:22:54.783763 | PLAY [localhost]
2025-11-06 00:22:54.797337 | 
2025-11-06 00:22:54.797455 | TASK [Run Zuul manifest role]
2025-11-06 00:22:54.836315 | localhost | ok
2025-11-06 00:22:54.850526 | 
2025-11-06 00:22:54.850640 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-06 00:22:55.225508 | localhost | changed
2025-11-06 00:22:55.231071 | 
2025-11-06 00:22:55.231161 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-06 00:22:55.259514 | localhost | ok
2025-11-06 00:22:55.267539 | 
2025-11-06 00:22:55.267603 | TASK [Set zuul-log-path fact]
2025-11-06 00:22:55.284645 | localhost | ok
2025-11-06 00:22:55.299363 | 
2025-11-06 00:22:55.299451 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-06 00:22:55.328190 | localhost | ok
2025-11-06 00:22:55.344763 | 
2025-11-06 00:22:55.344877 | LOOP [Run upload-logs-swift role]
2025-11-06 00:22:55.373375 | localhost | Output suppressed because no_log was given
2025-11-06 00:22:55.419914 | 
2025-11-06 00:22:55.420921 | TASK [Set zuul-log-path fact]
2025-11-06 00:22:55.470028 | localhost | skipping: Conditional result was False
2025-11-06 00:22:55.480055 | 
2025-11-06 00:22:55.480189 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-06 00:22:55.880923 | localhost -> localhost | ok: Runtime: 0:00:00.005367
2025-11-06 00:22:55.886136 | 
2025-11-06 00:22:55.886213 | TASK [upload-logs-swift : Upload logs to swift]