2026-02-15 00:06:46.399258 | Job console starting...
2026-02-15 00:06:46.409326 | Updating repositories
2026-02-15 00:06:46.514325 | Preparing job workspace
2026-02-15 00:06:50.636984 | Running Ansible setup...
2026-02-15 00:06:56.107162 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:06:56.885725 | 
2026-02-15 00:06:56.885867 | PLAY [localhost]
2026-02-15 00:06:56.894596 | 
2026-02-15 00:06:56.894692 | TASK [Gathering Facts]
2026-02-15 00:06:57.968972 | localhost | ok
2026-02-15 00:06:57.995205 | 
2026-02-15 00:06:57.995343 | TASK [Setup log path fact]
2026-02-15 00:06:58.015731 | localhost | ok
2026-02-15 00:06:58.033181 | 
2026-02-15 00:06:58.033274 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:06:58.064050 | localhost | ok
2026-02-15 00:06:58.075009 | 
2026-02-15 00:06:58.075106 | TASK [emit-job-header : Print job information]
2026-02-15 00:06:58.115863 | # Job Information
2026-02-15 00:06:58.116022 | Ansible Version: 2.15.12
2026-02-15 00:06:58.116065 | Job: ansible-test-sanity-docker-milestone
2026-02-15 00:06:58.116094 | Pipeline: periodic
2026-02-15 00:06:58.116119 | Executor: ze04.softwarefactory-project.io
2026-02-15 00:06:58.116144 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-15 00:06:58.116172 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/be2/ansible/be2ddde0c183496881dd19d72b5ef10d/
2026-02-15 00:06:58.116198 | Event ID: bfcfc7f67e194cfab2f082a1d8ce3d78
2026-02-15 00:06:58.121359 | 
2026-02-15 00:06:58.121443 | LOOP [emit-job-header : Print node information]
2026-02-15 00:06:58.231203 | localhost | ok:
2026-02-15 00:06:58.231453 | localhost | # Node Information
2026-02-15 00:06:58.231481 | localhost | Inventory Hostname: controller
2026-02-15 00:06:58.231501 | localhost | Hostname: np0005620022
2026-02-15 00:06:58.231520 | localhost | Username: zuul
2026-02-15 00:06:58.231551 | localhost | Distro: Fedora 37
2026-02-15 00:06:58.231570 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-15 00:06:58.231588 | localhost | Region: ca-ymq-1
2026-02-15 00:06:58.231604 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-15 00:06:58.231620 | localhost | Product Name: OpenStack Nova
2026-02-15 00:06:58.231637 | localhost | Interface IP: 162.253.55.195
2026-02-15 00:06:58.257150 | 
2026-02-15 00:06:58.257366 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-15 00:06:58.708588 | localhost -> localhost | changed
2026-02-15 00:06:58.724058 | 
2026-02-15 00:06:58.724229 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-15 00:06:59.874693 | localhost -> localhost | changed
2026-02-15 00:06:59.896440 | 
2026-02-15 00:06:59.896587 | PLAY [all:!appliance*]
2026-02-15 00:06:59.913517 | 
2026-02-15 00:06:59.913584 | TASK [include_role : start-zuul-console]
2026-02-15 00:06:59.933272 | controller | ok
2026-02-15 00:06:59.947100 | 
2026-02-15 00:06:59.947182 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-15 00:07:00.317548 | controller | ok
2026-02-15 00:07:00.333174 | 
2026-02-15 00:07:00.333279 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-15 00:07:01.187939 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-15 00:07:01.205276 | 
2026-02-15 00:07:01.205444 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-15 00:07:01.768864 | controller | skipping: Conditional result was False
2026-02-15 00:07:01.782917 | 
2026-02-15 00:07:01.783079 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-15 00:07:01.811591 | controller | skipping: Conditional result was False
2026-02-15 00:07:01.829153 | 
2026-02-15 00:07:01.829295 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-15 00:07:01.884314 | controller | skipping: Conditional result was False
2026-02-15 00:07:01.892637 | 
2026-02-15 00:07:01.892766 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-15 00:07:01.917660 | controller | skipping: Conditional result was False
2026-02-15 00:07:01.926871 | 
2026-02-15 00:07:01.927027 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-15 00:07:01.953234 | controller | skipping: Conditional result was False
2026-02-15 00:07:01.968603 | 
2026-02-15 00:07:01.968805 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-15 00:07:01.996564 | controller | skipping: Conditional result was False
2026-02-15 00:07:02.022203 | 
2026-02-15 00:07:02.022352 | TASK [Disable Fedora Modular]
2026-02-15 00:07:02.315577 | controller | changed
2026-02-15 00:07:02.330344 | 
2026-02-15 00:07:02.330496 | TASK [Enable EPEL]
2026-02-15 00:07:02.363243 | controller | skipping: Conditional result was False
2026-02-15 00:07:02.374180 | 
2026-02-15 00:07:02.374301 | TASK [Register the RHEL node]
2026-02-15 00:07:02.923258 | 
2026-02-15 00:07:02.923433 | TASK [Show the subscription-manager status]
2026-02-15 00:07:03.487839 | controller | skipping: Conditional result was False
2026-02-15 00:07:03.501618 | 
2026-02-15 00:07:03.501806 | TASK [Enable EPEL on RHEL]
2026-02-15 00:07:04.058808 | controller | skipping: Conditional result was False
2026-02-15 00:07:04.067457 | 
2026-02-15 00:07:04.067538 | TASK [Install git and tox]
2026-02-15 00:08:25.753798 | controller | changed
2026-02-15 00:08:25.760665 | 
2026-02-15 00:08:25.760760 | TASK [include_role : prepare-workspace]
2026-02-15 00:08:25.790745 | controller | ok
2026-02-15 00:08:25.840645 | 
2026-02-15 00:08:25.840890 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-15 00:08:26.097494 | controller | ok
2026-02-15 00:08:26.107738 | 
2026-02-15 00:08:26.107841 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-15 00:08:42.498887 | controller | Output suppressed because no_log was given
2026-02-15 00:08:42.563263 | 
2026-02-15 00:08:42.563399 | TASK [include_role : prepare-workspace-openshift]
2026-02-15 00:08:42.591178 | controller | skipping: Conditional result was False
2026-02-15 00:08:42.632384 | 
2026-02-15 00:08:42.632474 | PLAY [all:!appliance]
2026-02-15 00:08:42.656228 | 
2026-02-15 00:08:42.656346 | TASK [Run add-build-sshkey role (RSA)]
2026-02-15 00:08:42.702763 | controller | ok
2026-02-15 00:08:42.724194 | 
2026-02-15 00:08:42.724284 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:08:43.057322 | controller -> localhost | ok
2026-02-15 00:08:43.064371 | 
2026-02-15 00:08:43.064447 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:08:43.097178 | controller | ok
2026-02-15 00:08:43.111512 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:08:43.117602 | 
2026-02-15 00:08:43.117675 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:08:43.619662 | controller -> localhost | Generating public/private rsa key pair.
2026-02-15 00:08:43.620094 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_rsa.
2026-02-15 00:08:43.620160 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_rsa.pub.
2026-02-15 00:08:43.620206 | controller -> localhost | The key fingerprint is:
2026-02-15 00:08:43.620249 | controller -> localhost | SHA256:kSPdx28UJ9wlYnSzIwHkX362lTYULmNI4wBOMPBVziA zuul-build-sshkey
2026-02-15 00:08:43.620290 | controller -> localhost | The key's randomart image is:
2026-02-15 00:08:43.620329 | controller -> localhost | +---[RSA 2048]----+
2026-02-15 00:08:43.620369 | controller -> localhost | |   ..E.=o+o==.*o+|
2026-02-15 00:08:43.620410 | controller -> localhost | |    . *.+++oo+oBo|
2026-02-15 00:08:43.620453 | controller -> localhost | |     ...=ooo++=o |
2026-02-15 00:08:43.620493 | controller -> localhost | |       . o o.*+..|
2026-02-15 00:08:43.620532 | controller -> localhost | |        S   . +++|
2026-02-15 00:08:43.620590 | controller -> localhost | |             ..o+|
2026-02-15 00:08:43.620661 | controller -> localhost | |               . |
2026-02-15 00:08:43.620753 | controller -> localhost | |                 |
2026-02-15 00:08:43.620798 | controller -> localhost | |                 |
2026-02-15 00:08:43.620843 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:08:43.620940 | controller -> localhost | ok: Runtime: 0:00:00.137566
2026-02-15 00:08:43.636111 | 
2026-02-15 00:08:43.636254 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:08:43.671897 | controller | ok
2026-02-15 00:08:43.685624 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:08:43.697756 | 
2026-02-15 00:08:43.697846 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:08:43.722935 | controller | skipping: Conditional result was False
2026-02-15 00:08:43.732231 | 
2026-02-15 00:08:43.732321 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:08:44.190941 | controller | changed
2026-02-15 00:08:44.205562 | 
2026-02-15 00:08:44.205775 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:08:44.445265 | controller | ok
2026-02-15 00:08:44.458348 | 
2026-02-15 00:08:44.458500 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:08:45.123296 | controller | changed
2026-02-15 00:08:45.136475 | 
2026-02-15 00:08:45.136611 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:08:45.781885 | controller | changed
2026-02-15 00:08:45.794909 | 
2026-02-15 00:08:45.795063 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:08:45.822990 | controller | skipping: Conditional result was False
2026-02-15 00:08:45.837791 | 
2026-02-15 00:08:45.837936 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:08:46.332352 | controller -> localhost | changed
2026-02-15 00:08:46.344036 | 
2026-02-15 00:08:46.344163 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:08:46.737422 | controller -> localhost | Identity added: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_rsa (zuul-build-sshkey)
2026-02-15 00:08:46.737852 | controller -> localhost | ok: Runtime: 0:00:00.010417
2026-02-15 00:08:46.752397 | 
2026-02-15 00:08:46.752532 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:13:50.123760 | controller | ok
2026-02-15 00:13:50.137931 | 
2026-02-15 00:13:50.138148 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:13:50.188048 | controller | skipping: Conditional result was False
2026-02-15 00:13:50.207719 | 
2026-02-15 00:13:50.207911 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-15 00:13:50.245424 | controller | ok
2026-02-15 00:13:50.274541 | 
2026-02-15 00:13:50.274781 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:13:50.547383 | controller -> localhost | ok
2026-02-15 00:13:50.556010 | 
2026-02-15 00:13:50.556113 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:13:50.590563 | controller | ok
2026-02-15 00:13:50.606549 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:13:50.616063 | 
2026-02-15 00:13:50.616169 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:13:51.011504 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-15 00:13:51.011856 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_ecdsa.
2026-02-15 00:13:51.011898 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_ecdsa.pub.
2026-02-15 00:13:51.011937 | controller -> localhost | The key fingerprint is:
2026-02-15 00:13:51.011964 | controller -> localhost | SHA256:8DYOWgeEjzj/UEeaEDtOh3h1DVcW8ow0DgppuTgQ/sI zuul-build-sshkey
2026-02-15 00:13:51.011990 | controller -> localhost | The key's randomart image is:
2026-02-15 00:13:51.012015 | controller -> localhost | +---[ECDSA 521]---+
2026-02-15 00:13:51.012039 | controller -> localhost | |..  o=o +o=.+.   |
2026-02-15 00:13:51.012062 | controller -> localhost | |o  .** o.=.B     |
2026-02-15 00:13:51.012086 | controller -> localhost | | o.+*==+  o o    |
2026-02-15 00:13:51.012109 | controller -> localhost | |. *+oo=+.        |
2026-02-15 00:13:51.012132 | controller -> localhost | | E =..o.S        |
2026-02-15 00:13:51.012156 | controller -> localhost | |  . oo = .       |
2026-02-15 00:13:51.012179 | controller -> localhost | |    .o  .        |
2026-02-15 00:13:51.012202 | controller -> localhost | |      .          |
2026-02-15 00:13:51.012225 | controller -> localhost | |                 |
2026-02-15 00:13:51.012249 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:13:51.012307 | controller -> localhost | ok: Runtime: 0:00:00.019188
2026-02-15 00:13:51.085092 | 
2026-02-15 00:13:51.085285 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:13:51.118471 | controller | ok
2026-02-15 00:13:51.127764 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:13:51.138197 | 
2026-02-15 00:13:51.138375 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:13:51.165341 | controller | skipping: Conditional result was False
2026-02-15 00:13:51.176051 | 
2026-02-15 00:13:51.176169 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:13:51.466214 | controller | changed
2026-02-15 00:13:51.475879 | 
2026-02-15 00:13:51.475958 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:13:51.714604 | controller | ok
2026-02-15 00:13:51.722986 | 
2026-02-15 00:13:51.723081 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:13:52.429106 | controller | changed
2026-02-15 00:13:52.443927 | 
2026-02-15 00:13:52.444090 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:13:53.091210 | controller | changed
2026-02-15 00:13:53.105572 | 
2026-02-15 00:13:53.105778 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:13:53.133802 | controller | skipping: Conditional result was False
2026-02-15 00:13:53.143578 | 
2026-02-15 00:13:53.143714 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:13:53.439021 | controller -> localhost | changed
2026-02-15 00:13:53.458753 | 
2026-02-15 00:13:53.458883 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:13:53.814006 | controller -> localhost | Identity added: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/be2ddde0c183496881dd19d72b5ef10d_id_ecdsa (zuul-build-sshkey)
2026-02-15 00:13:53.814348 | controller -> localhost | ok: Runtime: 0:00:00.011190
2026-02-15 00:13:53.827847 | 
2026-02-15 00:13:53.827955 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:13:54.065155 | controller | ok
2026-02-15 00:13:54.074504 | 
2026-02-15 00:13:54.074721 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:13:54.120927 | controller | skipping: Conditional result was False
2026-02-15 00:13:54.138845 | 
2026-02-15 00:13:54.139058 | TASK [include_role : remove-zuul-sshkey]
2026-02-15 00:13:54.156557 | controller | skipping: Conditional result was False
2026-02-15 00:13:54.171427 | 
2026-02-15 00:13:54.171616 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-15 00:13:54.416209 | controller | ok: "logs"
2026-02-15 00:13:54.416924 | controller | ok: All items complete
2026-02-15 00:13:54.417017 | 
2026-02-15 00:13:54.610781 | controller | ok: "artifacts"
2026-02-15 00:13:54.800872 | controller | ok: "docs"
2026-02-15 00:13:54.825723 | 
2026-02-15 00:13:54.825914 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-15 00:13:55.075293 | controller | changed: "logs"
2026-02-15 00:13:55.278514 | controller | changed: "artifacts"
2026-02-15 00:13:55.473873 | controller | changed: "docs"
2026-02-15 00:13:55.522347 | 
2026-02-15 00:13:55.522498 | PLAY RECAP
2026-02-15 00:13:55.522548 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-15 00:13:55.522582 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-15 00:13:55.522626 | 
2026-02-15 00:13:55.674192 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:13:55.675220 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:13:56.296881 | 
2026-02-15 00:13:56.297063 | PLAY [all]
2026-02-15 00:13:56.323468 | 
2026-02-15 00:13:56.323654 | TASK [Install binary dependencies]
2026-02-15 00:13:56.401396 | controller | ok
2026-02-15 00:13:56.430850 | 
2026-02-15 00:13:56.431027 | TASK [bindep : Include find tasks]
2026-02-15 00:13:56.481450 | controller | ok
2026-02-15 00:13:56.489567 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-15 00:13:56.496028 | 
2026-02-15 00:13:56.496102 | TASK [bindep : Look for bindep.txt]
2026-02-15 00:13:57.332950 | controller | ok
2026-02-15 00:13:57.347905 | 
2026-02-15 00:13:57.348100 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:13:57.386314 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.396601 | 
2026-02-15 00:13:57.396817 | TASK [bindep : Look for other-requirements.txt]
2026-02-15 00:13:57.630768 | controller | ok
2026-02-15 00:13:57.645333 | 
2026-02-15 00:13:57.645501 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:13:57.683667 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.699527 | 
2026-02-15 00:13:57.699732 | TASK [bindep : Look for bindep fallback file]
2026-02-15 00:13:57.737475 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.753309 | 
2026-02-15 00:13:57.753638 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:13:57.782138 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.796634 | 
2026-02-15 00:13:57.796848 | TASK [bindep : Include bindep tasks]
2026-02-15 00:13:57.823870 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.841345 | 
2026-02-15 00:13:57.841555 | TASK [bindep : Include install tasks]
2026-02-15 00:13:57.870514 | controller | skipping: Conditional result was False
2026-02-15 00:13:57.887385 | 
2026-02-15 00:13:57.887625 | LOOP [bindep : Include package tasks]
2026-02-15 00:13:57.965018 | 
2026-02-15 00:13:57.965341 | TASK [Run test-setup role]
2026-02-15 00:13:57.991001 | controller | ok
2026-02-15 00:13:58.016169 | 
2026-02-15 00:13:58.016318 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-15 00:13:58.248095 | controller | ok
2026-02-15 00:13:58.261140 | 
2026-02-15 00:13:58.261314 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-15 00:13:58.814263 | controller | skipping: Conditional result was False
2026-02-15 00:13:58.852537 | 
2026-02-15 00:13:58.852768 | PLAY RECAP
2026-02-15 00:13:58.852857 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:13:58.852890 | 
2026-02-15 00:13:58.984511 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:13:58.986541 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:13:59.601791 | 
2026-02-15 00:13:59.601941 | PLAY [controller]
2026-02-15 00:13:59.621649 | 
2026-02-15 00:13:59.621772 | TASK [Create the /root directory]
2026-02-15 00:14:00.285363 | controller | ok
2026-02-15 00:14:00.301302 | 
2026-02-15 00:14:00.301571 | TASK [Install glibc-langpack-en]
2026-02-15 00:14:04.287002 | controller | ok: Nothing to do
2026-02-15 00:14:04.300360 | 
2026-02-15 00:14:04.300499 | TASK [Ensure controller directory exists]
2026-02-15 00:14:04.525176 | controller | changed
2026-02-15 00:14:04.538129 | 
2026-02-15 00:14:04.538267 | TASK [Install container runtime]
2026-02-15 00:14:04.631278 | controller | ok
2026-02-15 00:14:04.695578 | 
2026-02-15 00:14:04.695843 | LOOP [ensure-podman : Find distribution installation]
2026-02-15 00:14:04.735606 | controller | ok: "/var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-15 00:14:04.748212 | controller | included: /var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-15 00:14:04.763021 | 
2026-02-15 00:14:04.763215 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-15 00:15:19.956938 | controller | changed
2026-02-15 00:15:19.972334 | 
2026-02-15 00:15:19.972497 | TASK [ensure-podman : Fetch podman version]
2026-02-15 00:15:20.533437 | controller | Client:       Podman Engine
2026-02-15 00:15:20.567001 | controller | Version:      4.6.2
2026-02-15 00:15:20.567040 | controller | API Version:  4.6.2
2026-02-15 00:15:20.567048 | controller | Go Version:   go1.19.12
2026-02-15 00:15:20.567065 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:15:20.567073 | controller | OS/Arch:      linux/amd64
2026-02-15 00:15:21.026041 | controller | ok: Runtime: 0:00:00.182231
2026-02-15 00:15:21.040655 | 
2026-02-15 00:15:21.040980 | TASK [ensure-podman : Print podman version installed]
2026-02-15 00:15:21.092468 | Podman version: Client:       Podman Engine
2026-02-15 00:15:21.092897 | Version:      4.6.2
2026-02-15 00:15:21.092973 | API Version:  4.6.2
2026-02-15 00:15:21.093021 | Go Version:   go1.19.12
2026-02-15 00:15:21.093066 | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:15:21.093115 | OS/Arch:      linux/amd64
2026-02-15 00:15:21.106193 | 
2026-02-15 00:15:21.106357 | TASK [ensure-podman : Validate podman engine]
2026-02-15 00:15:21.648825 | controller | skipping: Conditional result was False
2026-02-15 00:15:21.658288 | 
2026-02-15 00:15:21.658391 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-15 00:15:21.685294 | controller | skipping: Conditional result was False
2026-02-15 00:15:21.700878 | 
2026-02-15 00:15:21.701175 | TASK [Ensure python3.8 is present]
2026-02-15 00:15:21.729562 | controller | skipping: Conditional result was False
2026-02-15 00:15:21.736818 | 
2026-02-15 00:15:21.736891 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-15 00:15:21.758707 | controller | ok
2026-02-15 00:15:21.777937 | 
2026-02-15 00:15:21.778055 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-15 00:15:23.292239 | controller | ok: Nothing to do
2026-02-15 00:15:23.297918 | 
2026-02-15 00:15:23.297982 | TASK [our-ensure-python : Also install python3-devel]
2026-02-15 00:15:32.375231 | controller | changed
2026-02-15 00:15:32.402541 | 
2026-02-15 00:15:32.402834 | TASK [Run ensure-virtualenv role]
2026-02-15 00:15:32.427579 | controller | ok
2026-02-15 00:15:32.459112 | 
2026-02-15 00:15:32.459289 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-15 00:15:32.678047 | controller | /usr/bin/virtualenv
2026-02-15 00:15:32.992937 | controller | ok: Runtime: 0:00:00.004879
2026-02-15 00:15:33.007073 | 
2026-02-15 00:15:33.007244 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-15 00:15:33.048577 | controller | skipping: Conditional result was False
2026-02-15 00:15:33.049092 | controller | ok: All items complete
2026-02-15 00:15:33.049154 | 
2026-02-15 00:15:33.084092 | 
2026-02-15 00:15:33.084370 | TASK [Find the full path of the Python interpreter]
2026-02-15 00:15:33.384797 | controller | /usr/bin/python3
2026-02-15 00:15:33.685474 | controller | ok
2026-02-15 00:15:33.704398 | 
2026-02-15 00:15:33.704673 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-15 00:15:34.503024 | controller | created virtual environment CPython3.11.0.final.0-64 in 479ms
2026-02-15 00:15:34.534109 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-15 00:15:34.534906 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2026-02-15 00:15:34.535252 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-15 00:15:34.535297 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-15 00:15:34.777174 | controller | changed
2026-02-15 00:15:34.791805 | 
2026-02-15 00:15:34.791994 | TASK [Set selinux package]
2026-02-15 00:15:34.823946 | controller | ok
2026-02-15 00:15:34.835331 | 
2026-02-15 00:15:34.835497 | TASK [Set selinux package (Fedora)]
2026-02-15 00:15:34.902914 | controller | ok
2026-02-15 00:15:34.915472 | 
2026-02-15 00:15:34.915632 | TASK [Install selinux into virtualenv]
2026-02-15 00:16:00.429925 | controller | Collecting selinux-please-lie-to-me
2026-02-15 00:16:12.679042 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-15 00:16:13.005191 | controller | Collecting setuptools<50.0.0
2026-02-15 00:16:13.010081 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-15 00:16:13.045695 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.2 MB/s eta 0:00:00
2026-02-15 00:16:13.129487 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-15 00:16:13.129736 | controller |   Attempting uninstall: setuptools
2026-02-15 00:16:13.132171 | controller |     Found existing installation: setuptools 62.6.0
2026-02-15 00:16:13.192624 | controller |     Uninstalling setuptools-62.6.0:
2026-02-15 00:16:13.200518 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-15 00:16:13.563404 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-15 00:16:25.059624 | controller |
2026-02-15 00:16:25.135955 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:16:25.136006 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:16:25.494149 | controller | ok: Runtime: 0:00:49.973862
2026-02-15 00:16:25.502773 | 
2026-02-15 00:16:25.502930 | TASK [Install pytest-forked into virtualenv]
2026-02-15 00:16:37.330139 | controller | Collecting pytest-forked
2026-02-15 00:16:49.545160 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-15 00:16:49.599181 | controller | Collecting py
2026-02-15 00:16:49.603724 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-15 00:16:49.623828 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.6 MB/s eta 0:00:00
2026-02-15 00:16:49.732736 | controller | Collecting pytest>=3.10
2026-02-15 00:16:49.737792 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-15 00:16:49.754463 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.0 MB/s eta 0:00:00
2026-02-15 00:16:49.795657 | controller | Collecting iniconfig>=1.0.1
2026-02-15 00:16:49.799382 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-15 00:16:49.845586 | controller | Collecting packaging>=22
2026-02-15 00:16:49.848964 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-15 00:16:49.853632 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 23.5 MB/s eta 0:00:00
2026-02-15 00:16:49.889315 | controller | Collecting pluggy<2,>=1.5
2026-02-15 00:16:49.892645 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-15 00:16:49.951500 | controller | Collecting pygments>=2.7.2
2026-02-15 00:16:49.957350 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-15 00:16:49.984423 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.3 MB/s eta 0:00:00
2026-02-15 00:16:50.054861 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-15 00:16:51.129488 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-02-15 00:16:51.138015 | controller |
2026-02-15 00:16:51.205656 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:16:51.205698 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:16:51.549816 | controller | ok: Runtime: 0:00:25.472351
2026-02-15 00:16:51.557838 | 
2026-02-15 00:16:51.557966 | TASK [Update pip]
2026-02-15 00:16:52.098338 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-15 00:17:01.962904 | controller | Collecting pip
2026-02-15 00:17:14.313127 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-15 00:17:14.371051 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.2 MB/s eta 0:00:00
2026-02-15 00:17:14.438887 | controller | Installing collected packages: pip
2026-02-15 00:17:14.439130 | controller |   Attempting uninstall: pip
2026-02-15 00:17:14.441562 | controller |     Found existing installation: pip 22.2.2
2026-02-15 00:17:14.582955 | controller |     Uninstalling pip-22.2.2:
2026-02-15 00:17:14.598201 | controller |       Successfully uninstalled pip-22.2.2
2026-02-15 00:17:15.418767 | controller | Successfully installed pip-26.0.1
2026-02-15 00:17:15.605450 | controller | ok: Runtime: 0:00:23.723557
2026-02-15 00:17:15.619247 | 
2026-02-15 00:17:15.619776 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-15 00:17:15.856017 | controller | changed
2026-02-15 00:17:15.870549 | 
2026-02-15 00:17:15.870754 | TASK [Install ansible into virtualenv]
2026-02-15 00:17:16.383704 | controller | Processing ./src/github.com/ansible/ansible
2026-02-15 00:17:16.386308 | controller |   Installing build dependencies: started
2026-02-15 00:17:37.199051 | controller |   Installing build dependencies: finished with status 'done'
2026-02-15 00:17:37.200226 | controller |   Getting requirements to build wheel: started
2026-02-15 00:17:37.963239 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-15 00:17:37.964167 | controller |   Preparing metadata (pyproject.toml): started
2026-02-15 00:17:38.422868 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-15 00:17:38.425099 | 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.
2026-02-15 00:17:38.427598 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-15 00:17:38.941481 | controller | ERROR
2026-02-15 00:17:38.941879 | controller | {
2026-02-15 00:17:38.941959 | controller |   "delta": "0:00:22.383781",
2026-02-15 00:17:38.942032 | controller |   "end": "2026-02-15 00:17:38.486672",
2026-02-15 00:17:38.942078 | controller |   "msg": "non-zero return code",
2026-02-15 00:17:38.942154 | controller |   "rc": 1,
2026-02-15 00:17:38.942224 | controller |   "start": "2026-02-15 00:17:16.102891"
2026-02-15 00:17:38.942286 | controller | }
failure
2026-02-15 00:17:38.946170 | 
2026-02-15 00:17:38.946272 | PLAY RECAP
2026-02-15 00:17:38.946360 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-15 00:17:38.946405 | 
2026-02-15 00:17:39.140210 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:17:39.141337 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:17:39.799020 | 
2026-02-15 00:17:39.799184 | PLAY [all]
2026-02-15 00:17:39.824256 | 
2026-02-15 00:17:39.824377 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-15 00:17:40.276012 | controller | changed: non-zero return code
2026-02-15 00:17:40.292502 | 
2026-02-15 00:17:40.292853 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-15 00:17:40.322562 | controller | skipping: Conditional result was False
2026-02-15 00:17:40.339059 | 
2026-02-15 00:17:40.339288 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-15 00:17:40.386800 | 
2026-02-15 00:17:40.387186 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-15 00:17:40.431391 | 
2026-02-15 00:17:40.431769 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-15 00:17:40.460881 | controller | skipping: Conditional result was False
2026-02-15 00:17:40.478812 | 
2026-02-15 00:17:40.479047 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-15 00:17:40.518955 | 
2026-02-15 00:17:40.519218 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-15 00:17:40.546905 | controller | skipping: Conditional result was False
2026-02-15 00:17:40.556907 | 
2026-02-15 00:17:40.557062 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-15 00:17:40.584126 | controller | skipping: Conditional result was False
2026-02-15 00:17:40.595432 | 
2026-02-15 00:17:40.595769 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-15 00:17:40.622588 | controller | skipping: Conditional result was False
2026-02-15 00:17:40.666025 | 
2026-02-15 00:17:40.666218 | PLAY RECAP
2026-02-15 00:17:40.666294 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:17:40.666338 | 
2026-02-15 00:17:40.853100 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:17:40.854549 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-15 00:17:41.544971 | 
2026-02-15 00:17:41.545209 | PLAY [all:!appliance*]
2026-02-15 00:17:41.577619 | 
2026-02-15 00:17:41.577832 | TASK [unregister the node]
2026-02-15 00:17:42.112779 | controller | skipping: Conditional result was False
2026-02-15 00:17:42.126319 | 
2026-02-15 00:17:42.126527 | TASK [include_role : fetch-output]
2026-02-15 00:17:42.168484 | controller | ok
2026-02-15 00:17:42.215356 | 
2026-02-15 00:17:42.215538 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-15 00:17:42.262549 | controller | skipping: Conditional result was False
2026-02-15 00:17:42.276737 | 
2026-02-15 00:17:42.276964 | TASK [fetch-output : Set log path for single node]
2026-02-15 00:17:42.327786 | controller | ok
2026-02-15 00:17:42.340639 | 
2026-02-15 00:17:42.340929 | LOOP [fetch-output : Ensure local output dirs]
2026-02-15 00:17:42.797184 | controller -> localhost | ok: "/var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/logs"
2026-02-15 00:17:43.086409 | controller -> localhost | changed: "/var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/artifacts"
2026-02-15 00:17:43.360418 | controller -> localhost | changed: "/var/lib/zuul/builds/be2ddde0c183496881dd19d72b5ef10d/work/docs"
2026-02-15 00:17:43.370847 | 
2026-02-15 00:17:43.371000 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-15 00:17:44.052280 | controller | changed:
2026-02-15 00:17:44.052832 | controller | .d..t...... ./
2026-02-15 00:17:44.052875 | controller | cd+++++++++ controller/
2026-02-15 00:17:44.052917 | controller | changed: All items complete
2026-02-15 00:17:44.052939 | 
2026-02-15 00:17:44.633328 | controller | changed: .d..t...... ./
2026-02-15 00:17:45.202447 | controller | changed: .d..t...... ./
2026-02-15 00:17:45.243084 | 
2026-02-15 00:17:45.243342 | TASK [include_role : fetch-output-openshift]
2026-02-15 00:17:45.274236 | controller | skipping: Conditional result was False
2026-02-15 00:17:45.288710 | 
2026-02-15 00:17:45.289208 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-15 00:17:45.338092 | controller | skipping: Conditional result was False
2026-02-15 00:17:45.351227 | controller | skipping: Conditional result was False
2026-02-15 00:17:45.390764 | 
2026-02-15 00:17:45.390943 | PLAY [localhost]
2026-02-15 00:17:45.410489 | 
2026-02-15 00:17:45.410610 | TASK [Run Zuul manifest role]
2026-02-15 00:17:45.431146 | localhost | ok
2026-02-15 00:17:45.447282 | 
2026-02-15 00:17:45.447391 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-15 00:17:45.924158 | localhost | changed
2026-02-15 00:17:45.936270 | 
2026-02-15 00:17:45.936501 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-15 00:17:45.985901 | localhost | ok
2026-02-15 00:17:46.005456 | 
2026-02-15 00:17:46.005738 | TASK [Set zuul-log-path fact]
2026-02-15 00:17:46.035017 | localhost | ok
2026-02-15 00:17:46.060582 | 
2026-02-15 00:17:46.060742 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:17:46.104897 | localhost | ok
2026-02-15 00:17:46.117217 | 
2026-02-15 00:17:46.117326 | LOOP [Run upload-logs-swift role]
2026-02-15 00:17:46.165589 | localhost | Output suppressed because no_log was given
2026-02-15 00:17:46.208552 | 
2026-02-15 00:17:46.208766 | TASK [Set zuul-log-path fact]
2026-02-15 00:17:46.246197 | localhost | skipping: Conditional result was False
2026-02-15 00:17:46.255104 | 
2026-02-15 00:17:46.255262 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-15 00:17:46.771145 | localhost -> localhost | ok: Runtime: 0:00:00.008501
2026-02-15 00:17:46.837060 | 
2026-02-15 00:17:46.837236 | TASK [upload-logs-swift : Upload logs to swift]