2026-02-13 00:06:41.701920 | Job console starting...
2026-02-13 00:06:41.715387 | Updating repositories
2026-02-13 00:06:42.458537 | Preparing job workspace
2026-02-13 00:06:50.154555 | Running Ansible setup...
2026-02-13 00:06:56.328189 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:06:57.007097 | 
2026-02-13 00:06:57.007252 | PLAY [localhost]
2026-02-13 00:06:57.016177 | 
2026-02-13 00:06:57.016261 | TASK [Gathering Facts]
2026-02-13 00:06:58.126729 | localhost | ok
2026-02-13 00:06:58.155464 | 
2026-02-13 00:06:58.155619 | TASK [Setup log path fact]
2026-02-13 00:06:58.176133 | localhost | ok
2026-02-13 00:06:58.193716 | 
2026-02-13 00:06:58.193836 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:06:58.225233 | localhost | ok
2026-02-13 00:06:58.236087 | 
2026-02-13 00:06:58.236193 | TASK [emit-job-header : Print job information]
2026-02-13 00:06:58.301370 | # Job Information
2026-02-13 00:06:58.301640 | Ansible Version: 2.15.12
2026-02-13 00:06:58.301712 | Job: ansible-test-sanity-docker-milestone
2026-02-13 00:06:58.301762 | Pipeline: periodic
2026-02-13 00:06:58.301826 | Executor: ze01.softwarefactory-project.io
2026-02-13 00:06:58.301873 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-13 00:06:58.301922 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/cd7/ansible/cd78417f9bef45c38202881df50a86f1/
2026-02-13 00:06:58.301966 | Event ID: 0fb89987ddbf4579b8946ad3b376b620
2026-02-13 00:06:58.311677 | 
2026-02-13 00:06:58.311840 | LOOP [emit-job-header : Print node information]
2026-02-13 00:06:58.445229 | localhost | ok:
2026-02-13 00:06:58.445484 | localhost | # Node Information
2026-02-13 00:06:58.445540 | localhost | Inventory Hostname: controller
2026-02-13 00:06:58.445582 | localhost | Hostname: np0005618398
2026-02-13 00:06:58.445622 | localhost | Username: zuul
2026-02-13 00:06:58.445667 | localhost | Distro: Fedora 37
2026-02-13 00:06:58.445706 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-13 00:06:58.445747 | localhost | Region: ca-ymq-1
2026-02-13 00:06:58.445784 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-13 00:06:58.445822 | localhost | Product Name: OpenStack Nova
2026-02-13 00:06:58.445859 | localhost | Interface IP: 162.253.55.62
2026-02-13 00:06:58.465117 | 
2026-02-13 00:06:58.465316 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-13 00:06:58.889001 | localhost -> localhost | changed
2026-02-13 00:06:58.894474 | 
2026-02-13 00:06:58.894543 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-13 00:06:59.827400 | localhost -> localhost | changed
2026-02-13 00:06:59.848038 | 
2026-02-13 00:06:59.848115 | PLAY [all:!appliance*]
2026-02-13 00:06:59.865286 | 
2026-02-13 00:06:59.865391 | TASK [include_role : start-zuul-console]
2026-02-13 00:06:59.885170 | controller | ok
2026-02-13 00:06:59.899086 | 
2026-02-13 00:06:59.899155 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-13 00:07:00.286796 | controller | ok
2026-02-13 00:07:00.311589 | 
2026-02-13 00:07:00.311728 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-13 00:07:01.286270 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-13 00:07:01.305944 | 
2026-02-13 00:07:01.306217 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-13 00:07:01.857050 | controller | skipping: Conditional result was False
2026-02-13 00:07:01.870876 | 
2026-02-13 00:07:01.871074 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-13 00:07:01.908008 | controller | skipping: Conditional result was False
2026-02-13 00:07:01.921194 | 
2026-02-13 00:07:01.921324 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-13 00:07:01.957472 | controller | skipping: Conditional result was False
2026-02-13 00:07:01.971764 | 
2026-02-13 00:07:01.971917 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-13 00:07:01.998725 | controller | skipping: Conditional result was False
2026-02-13 00:07:02.012529 | 
2026-02-13 00:07:02.012681 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-13 00:07:02.039655 | controller | skipping: Conditional result was False
2026-02-13 00:07:02.049701 | 
2026-02-13 00:07:02.049802 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-13 00:07:02.075135 | controller | skipping: Conditional result was False
2026-02-13 00:07:02.092561 | 
2026-02-13 00:07:02.092650 | TASK [Disable Fedora Modular]
2026-02-13 00:07:02.359914 | controller | changed
2026-02-13 00:07:02.373562 | 
2026-02-13 00:07:02.373776 | TASK [Enable EPEL]
2026-02-13 00:07:02.401470 | controller | skipping: Conditional result was False
2026-02-13 00:07:02.420886 | 
2026-02-13 00:07:02.421140 | TASK [Register the RHEL node]
2026-02-13 00:07:02.992100 | 
2026-02-13 00:07:02.992398 | TASK [Show the subscription-manager status]
2026-02-13 00:07:03.574286 | controller | skipping: Conditional result was False
2026-02-13 00:07:03.588893 | 
2026-02-13 00:07:03.589105 | TASK [Enable EPEL on RHEL]
2026-02-13 00:07:04.151522 | controller | skipping: Conditional result was False
2026-02-13 00:07:04.159944 | 
2026-02-13 00:07:04.160061 | TASK [Install git and tox]
2026-02-13 00:08:26.110063 | controller | changed
2026-02-13 00:08:26.120585 | 
2026-02-13 00:08:26.120684 | TASK [include_role : prepare-workspace]
2026-02-13 00:08:26.154783 | controller | ok
2026-02-13 00:08:26.183224 | 
2026-02-13 00:08:26.183535 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-13 00:08:26.452476 | controller | ok
2026-02-13 00:08:26.463287 | 
2026-02-13 00:08:26.463518 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-13 00:08:42.053104 | controller | Output suppressed because no_log was given
2026-02-13 00:08:42.067663 | 
2026-02-13 00:08:42.067796 | TASK [include_role : prepare-workspace-openshift]
2026-02-13 00:08:42.086628 | controller | skipping: Conditional result was False
2026-02-13 00:08:42.111418 | 
2026-02-13 00:08:42.111501 | PLAY [all:!appliance]
2026-02-13 00:08:42.128769 | 
2026-02-13 00:08:42.128874 | TASK [Run add-build-sshkey role (RSA)]
2026-02-13 00:08:42.150075 | controller | ok
2026-02-13 00:08:42.168061 | 
2026-02-13 00:08:42.168181 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:08:42.418105 | controller -> localhost | ok
2026-02-13 00:08:42.430458 | 
2026-02-13 00:08:42.430600 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:08:42.463242 | controller | ok
2026-02-13 00:08:42.489521 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:08:42.499513 | 
2026-02-13 00:08:42.499618 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:08:42.973935 | controller -> localhost | Generating public/private rsa key pair.
2026-02-13 00:08:42.974312 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_rsa.
2026-02-13 00:08:42.974362 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_rsa.pub.
2026-02-13 00:08:42.974396 | controller -> localhost | The key fingerprint is:
2026-02-13 00:08:42.974427 | controller -> localhost | SHA256:9Q1P1h/q+xe9dx5sa0Yej2wY2pRVyHqcZoL3O7yI9Xo zuul-build-sshkey
2026-02-13 00:08:42.974458 | controller -> localhost | The key's randomart image is:
2026-02-13 00:08:42.974489 | controller -> localhost | +---[RSA 2048]----+
2026-02-13 00:08:42.974519 | controller -> localhost | |             . . |
2026-02-13 00:08:42.974551 | controller -> localhost | |              o..|
2026-02-13 00:08:42.974582 | controller -> localhost | |          ...oo+.|
2026-02-13 00:08:42.974613 | controller -> localhost | |         ...+*O o|
2026-02-13 00:08:42.974642 | controller -> localhost | |        S  ..Xo o|
2026-02-13 00:08:42.974683 | controller -> localhost | |            = o+.|
2026-02-13 00:08:42.974725 | controller -> localhost | |           +.*o*=|
2026-02-13 00:08:42.974759 | controller -> localhost | |          .oooE=B|
2026-02-13 00:08:42.974789 | controller -> localhost | |          . o=**=|
2026-02-13 00:08:42.974824 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:08:42.974899 | controller -> localhost | ok: Runtime: 0:00:00.054462
2026-02-13 00:08:42.985505 | 
2026-02-13 00:08:42.985629 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:08:43.024723 | controller | ok
2026-02-13 00:08:43.040189 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:08:43.061790 | 
2026-02-13 00:08:43.062009 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:08:43.090188 | controller | skipping: Conditional result was False
2026-02-13 00:08:43.106440 | 
2026-02-13 00:08:43.106598 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:13:48.156077 | controller | ok
2026-02-13 00:13:48.169001 | 
2026-02-13 00:13:48.169207 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:13:48.402641 | controller | ok
2026-02-13 00:13:48.415263 | 
2026-02-13 00:13:48.415404 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:13:49.038741 | controller | changed
2026-02-13 00:13:49.053180 | 
2026-02-13 00:13:49.053501 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:13:49.693225 | controller | changed
2026-02-13 00:13:49.700125 | 
2026-02-13 00:13:49.700263 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:13:49.724526 | controller | skipping: Conditional result was False
2026-02-13 00:13:49.732653 | 
2026-02-13 00:13:49.732771 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:13:50.166869 | controller -> localhost | changed
2026-02-13 00:13:50.195531 | 
2026-02-13 00:13:50.195737 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:13:50.529189 | controller -> localhost | Identity added: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_rsa (zuul-build-sshkey)
2026-02-13 00:13:50.529436 | controller -> localhost | ok: Runtime: 0:00:00.008713
2026-02-13 00:13:50.536117 | 
2026-02-13 00:13:50.536183 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:13:50.933198 | controller | ok
2026-02-13 00:13:50.945164 | 
2026-02-13 00:13:50.945285 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:13:51.064502 | controller | skipping: Conditional result was False
2026-02-13 00:13:51.090574 | 
2026-02-13 00:13:51.090760 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-13 00:13:51.130334 | controller | ok
2026-02-13 00:13:51.155907 | 
2026-02-13 00:13:51.156061 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:13:51.450614 | controller -> localhost | ok
2026-02-13 00:13:51.467987 | 
2026-02-13 00:13:51.468491 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:13:51.500637 | controller | ok
2026-02-13 00:13:51.517471 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:13:51.525308 | 
2026-02-13 00:13:51.525457 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:13:51.871105 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-13 00:13:51.871408 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_ecdsa.
2026-02-13 00:13:51.871471 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_ecdsa.pub.
2026-02-13 00:13:51.871535 | controller -> localhost | The key fingerprint is:
2026-02-13 00:13:51.871594 | controller -> localhost | SHA256:84bLlb8CX28o3bRKqHQZ/9WV9YjfH1JnLzHusut2TuI zuul-build-sshkey
2026-02-13 00:13:51.871651 | controller -> localhost | The key's randomart image is:
2026-02-13 00:13:51.871680 | controller -> localhost | +---[ECDSA 521]---+
2026-02-13 00:13:51.871706 | controller -> localhost | |                 |
2026-02-13 00:13:51.871730 | controller -> localhost | |                 |
2026-02-13 00:13:51.871752 | controller -> localhost | |                .|
2026-02-13 00:13:51.871776 | controller -> localhost | |             . .+|
2026-02-13 00:13:51.871798 | controller -> localhost | |        S . . +o=|
2026-02-13 00:13:51.871822 | controller -> localhost | |        .+ *.oo==|
2026-02-13 00:13:51.871844 | controller -> localhost | |        ooOo+*=o=|
2026-02-13 00:13:51.871866 | controller -> localhost | |       o *++==Boo|
2026-02-13 00:13:51.871888 | controller -> localhost | |        +  =EX+ .|
2026-02-13 00:13:51.871910 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:13:51.871978 | controller -> localhost | ok: Runtime: 0:00:00.016870
2026-02-13 00:13:51.891211 | 
2026-02-13 00:13:51.891455 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:13:51.921265 | controller | ok
2026-02-13 00:13:51.932346 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:13:51.945459 | 
2026-02-13 00:13:51.945660 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:13:51.974071 | controller | skipping: Conditional result was False
2026-02-13 00:13:51.983900 | 
2026-02-13 00:13:51.984114 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:13:52.275462 | controller | changed
2026-02-13 00:13:52.283670 | 
2026-02-13 00:13:52.283769 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:13:52.509375 | controller | ok
2026-02-13 00:13:52.519816 | 
2026-02-13 00:13:52.519984 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:13:53.202363 | controller | changed
2026-02-13 00:13:53.211909 | 
2026-02-13 00:13:53.212127 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:13:53.885191 | controller | changed
2026-02-13 00:13:53.901679 | 
2026-02-13 00:13:53.901870 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:13:53.928735 | controller | skipping: Conditional result was False
2026-02-13 00:13:53.938997 | 
2026-02-13 00:13:53.939144 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:13:54.234662 | controller -> localhost | changed
2026-02-13 00:13:54.247222 | 
2026-02-13 00:13:54.247318 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:13:54.547994 | controller -> localhost | Identity added: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/cd78417f9bef45c38202881df50a86f1_id_ecdsa (zuul-build-sshkey)
2026-02-13 00:13:54.548245 | controller -> localhost | ok: Runtime: 0:00:00.008860
2026-02-13 00:13:54.555280 | 
2026-02-13 00:13:54.555342 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:13:54.784705 | controller | ok
2026-02-13 00:13:54.796787 | 
2026-02-13 00:13:54.796914 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:13:54.845710 | controller | skipping: Conditional result was False
2026-02-13 00:13:54.869848 | 
2026-02-13 00:13:54.870054 | TASK [include_role : remove-zuul-sshkey]
2026-02-13 00:13:54.897556 | controller | skipping: Conditional result was False
2026-02-13 00:13:54.907316 | 
2026-02-13 00:13:54.907481 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-13 00:13:55.155217 | controller | ok: "logs"
2026-02-13 00:13:55.155741 | controller | ok: All items complete
2026-02-13 00:13:55.155816 | 
2026-02-13 00:13:55.355467 | controller | ok: "artifacts"
2026-02-13 00:13:55.557155 | controller | ok: "docs"
2026-02-13 00:13:55.583865 | 
2026-02-13 00:13:55.584044 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-13 00:13:55.846924 | controller | changed: "logs"
2026-02-13 00:13:56.048753 | controller | changed: "artifacts"
2026-02-13 00:13:56.246254 | controller | changed: "docs"
2026-02-13 00:13:56.310995 | 
2026-02-13 00:13:56.311140 | PLAY RECAP
2026-02-13 00:13:56.311203 | controller | ok: 30 changed: 15 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-13 00:13:56.311241 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-13 00:13:56.311269 | 
2026-02-13 00:13:56.439848 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:13:56.441051 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:13:57.039517 | 
2026-02-13 00:13:57.039641 | PLAY [all]
2026-02-13 00:13:57.062956 | 
2026-02-13 00:13:57.063088 | TASK [Install binary dependencies]
2026-02-13 00:13:57.103333 | controller | ok
2026-02-13 00:13:57.133969 | 
2026-02-13 00:13:57.134128 | TASK [bindep : Include find tasks]
2026-02-13 00:13:57.165512 | controller | ok
2026-02-13 00:13:57.178896 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-13 00:13:57.186104 | 
2026-02-13 00:13:57.186177 | TASK [bindep : Look for bindep.txt]
2026-02-13 00:13:57.772868 | controller | ok
2026-02-13 00:13:57.787347 | 
2026-02-13 00:13:57.787528 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:13:57.815856 | controller | skipping: Conditional result was False
2026-02-13 00:13:57.833430 | 
2026-02-13 00:13:57.833597 | TASK [bindep : Look for other-requirements.txt]
2026-02-13 00:13:58.040990 | controller | ok
2026-02-13 00:13:58.049207 | 
2026-02-13 00:13:58.049309 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:13:58.084851 | controller | skipping: Conditional result was False
2026-02-13 00:13:58.100099 | 
2026-02-13 00:13:58.100259 | TASK [bindep : Look for bindep fallback file]
2026-02-13 00:13:58.137710 | controller | skipping: Conditional result was False
2026-02-13 00:13:58.147928 | 
2026-02-13 00:13:58.148060 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:13:58.184121 | controller | skipping: Conditional result was False
2026-02-13 00:13:58.192553 | 
2026-02-13 00:13:58.192659 | TASK [bindep : Include bindep tasks]
2026-02-13 00:13:58.227455 | controller | skipping: Conditional result was False
2026-02-13 00:13:58.243289 | 
2026-02-13 00:13:58.243446 | TASK [bindep : Include install tasks]
2026-02-13 00:13:58.279128 | controller | skipping: Conditional result was False
2026-02-13 00:13:58.288302 | 
2026-02-13 00:13:58.288431 | LOOP [bindep : Include package tasks]
2026-02-13 00:13:58.370483 | 
2026-02-13 00:13:58.370764 | TASK [Run test-setup role]
2026-02-13 00:13:58.397139 | controller | ok
2026-02-13 00:13:58.424668 | 
2026-02-13 00:13:58.424804 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-13 00:13:58.628510 | controller | ok
2026-02-13 00:13:58.634325 | 
2026-02-13 00:13:58.634383 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-13 00:13:59.165382 | controller | skipping: Conditional result was False
2026-02-13 00:13:59.218346 | 
2026-02-13 00:13:59.218457 | PLAY RECAP
2026-02-13 00:13:59.218513 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:13:59.218535 | 
2026-02-13 00:13:59.357065 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:13:59.358954 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:13:59.972288 | 
2026-02-13 00:13:59.972449 | PLAY [controller]
2026-02-13 00:13:59.993542 | 
2026-02-13 00:13:59.993680 | TASK [Create the /root directory]
2026-02-13 00:14:00.551196 | controller | ok
2026-02-13 00:14:00.562873 | 
2026-02-13 00:14:00.563055 | TASK [Install glibc-langpack-en]
2026-02-13 00:14:04.717837 | controller | ok: Nothing to do
2026-02-13 00:14:04.732728 | 
2026-02-13 00:14:04.732900 | TASK [Ensure controller directory exists]
2026-02-13 00:14:04.990855 | controller | changed
2026-02-13 00:14:05.006363 | 
2026-02-13 00:14:05.006587 | TASK [Install container runtime]
2026-02-13 00:14:05.084445 | controller | ok
2026-02-13 00:14:05.141474 | 
2026-02-13 00:14:05.141622 | LOOP [ensure-podman : Find distribution installation]
2026-02-13 00:14:05.171565 | controller | ok: "/var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-13 00:14:05.184641 | controller | included: /var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-13 00:14:05.192157 | 
2026-02-13 00:14:05.192262 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-13 00:15:08.642468 | controller | changed
2026-02-13 00:15:08.652636 | 
2026-02-13 00:15:08.652733 | TASK [ensure-podman : Fetch podman version]
2026-02-13 00:15:09.219913 | controller | Client:       Podman Engine
2026-02-13 00:15:09.246473 | controller | Version:      4.6.2
2026-02-13 00:15:09.246530 | controller | API Version:  4.6.2
2026-02-13 00:15:09.246543 | controller | Go Version:   go1.19.12
2026-02-13 00:15:09.246569 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:15:09.246581 | controller | OS/Arch:      linux/amd64
2026-02-13 00:15:09.717265 | controller | ok: Runtime: 0:00:00.182482
2026-02-13 00:15:09.726570 | 
2026-02-13 00:15:09.726903 | TASK [ensure-podman : Print podman version installed]
2026-02-13 00:15:09.785913 | Podman version: Client:       Podman Engine
2026-02-13 00:15:09.786126 | Version:      4.6.2
2026-02-13 00:15:09.786159 | API Version:  4.6.2
2026-02-13 00:15:09.786179 | Go Version:   go1.19.12
2026-02-13 00:15:09.786196 | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:15:09.786214 | OS/Arch:      linux/amd64
2026-02-13 00:15:09.792221 | 
2026-02-13 00:15:09.792311 | TASK [ensure-podman : Validate podman engine]
2026-02-13 00:15:10.325327 | controller | skipping: Conditional result was False
2026-02-13 00:15:10.339895 | 
2026-02-13 00:15:10.340105 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-13 00:15:10.377505 | controller | skipping: Conditional result was False
2026-02-13 00:15:10.407350 | 
2026-02-13 00:15:10.407529 | TASK [Ensure python3.8 is present]
2026-02-13 00:15:10.424811 | controller | skipping: Conditional result was False
2026-02-13 00:15:10.434953 | 
2026-02-13 00:15:10.435134 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-13 00:15:10.458001 | controller | ok
2026-02-13 00:15:10.488284 | 
2026-02-13 00:15:10.488430 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-13 00:15:11.947561 | controller | ok: Nothing to do
2026-02-13 00:15:11.956557 | 
2026-02-13 00:15:11.956681 | TASK [our-ensure-python : Also install python3-devel]
2026-02-13 00:15:21.018070 | controller | changed
2026-02-13 00:15:21.048639 | 
2026-02-13 00:15:21.048737 | TASK [Run ensure-virtualenv role]
2026-02-13 00:15:21.079613 | controller | ok
2026-02-13 00:15:21.103955 | 
2026-02-13 00:15:21.104099 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-13 00:15:21.326519 | controller | /usr/bin/virtualenv
2026-02-13 00:15:21.642818 | controller | ok: Runtime: 0:00:00.006134
2026-02-13 00:15:21.652666 | 
2026-02-13 00:15:21.652800 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-13 00:15:21.680407 | controller | skipping: Conditional result was False
2026-02-13 00:15:21.680662 | controller | ok: All items complete
2026-02-13 00:15:21.680696 | 
2026-02-13 00:15:21.705854 | 
2026-02-13 00:15:21.706076 | TASK [Find the full path of the Python interpreter]
2026-02-13 00:15:21.955425 | controller | /usr/bin/python3
2026-02-13 00:15:22.279105 | controller | ok
2026-02-13 00:15:22.285417 | 
2026-02-13 00:15:22.285539 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-13 00:15:23.122566 | controller | created virtual environment CPython3.11.0.final.0-64 in 538ms
2026-02-13 00:15:23.139025 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-13 00:15:23.139064 | 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-13 00:15:23.139074 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-13 00:15:23.139094 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-13 00:15:23.319901 | controller | changed
2026-02-13 00:15:23.329171 | 
2026-02-13 00:15:23.329306 | TASK [Set selinux package]
2026-02-13 00:15:23.352658 | controller | ok
2026-02-13 00:15:23.360998 | 
2026-02-13 00:15:23.361120 | TASK [Set selinux package (Fedora)]
2026-02-13 00:15:23.392920 | controller | ok
2026-02-13 00:15:23.398314 | 
2026-02-13 00:15:23.398380 | TASK [Install selinux into virtualenv]
2026-02-13 00:15:36.941032 | controller | Collecting selinux-please-lie-to-me
2026-02-13 00:15:49.183136 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-13 00:15:49.510213 | controller | Collecting setuptools<50.0.0
2026-02-13 00:15:49.527768 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-13 00:15:49.563215 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.1 MB/s eta 0:00:00
2026-02-13 00:15:49.644840 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-13 00:15:49.645360 | controller |   Attempting uninstall: setuptools
2026-02-13 00:15:49.651164 | controller |     Found existing installation: setuptools 62.6.0
2026-02-13 00:15:49.714673 | controller |     Uninstalling setuptools-62.6.0:
2026-02-13 00:15:49.722699 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-13 00:15:50.075770 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-13 00:16:01.577704 | controller |
2026-02-13 00:16:01.658070 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:16:01.658140 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:16:01.968166 | controller | ok: Runtime: 0:00:38.028321
2026-02-13 00:16:01.976896 | 
2026-02-13 00:16:01.976992 | TASK [Install pytest-forked into virtualenv]
2026-02-13 00:16:13.811155 | controller | Collecting pytest-forked
2026-02-13 00:16:24.118495 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-13 00:16:24.172336 | controller | Collecting py
2026-02-13 00:16:24.231965 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-13 00:16:24.253295 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.7 MB/s eta 0:00:00
2026-02-13 00:16:24.364416 | controller | Collecting pytest>=3.10
2026-02-13 00:16:24.524083 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-13 00:16:24.556325 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 13.1 MB/s eta 0:00:00
2026-02-13 00:16:24.606187 | controller | Collecting iniconfig>=1.0.1
2026-02-13 00:16:24.610143 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-13 00:16:24.658693 | controller | Collecting packaging>=22
2026-02-13 00:16:24.662842 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-13 00:16:24.671595 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 10.9 MB/s eta 0:00:00
2026-02-13 00:16:24.713529 | controller | Collecting pluggy<2,>=1.5
2026-02-13 00:16:24.719103 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-13 00:16:24.774263 | controller | Collecting pygments>=2.7.2
2026-02-13 00:16:24.788331 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-13 00:16:24.819521 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 45.6 MB/s eta 0:00:00
2026-02-13 00:16:24.888007 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-13 00:16:25.960996 | 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-13 00:16:25.970480 | controller |
2026-02-13 00:16:26.043009 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:16:26.043039 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:16:26.537596 | controller | ok: Runtime: 0:00:23.840123
2026-02-13 00:16:26.553183 | 
2026-02-13 00:16:26.553372 | TASK [Update pip]
2026-02-13 00:16:27.081133 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-13 00:16:39.551282 | controller | Collecting pip
2026-02-13 00:16:51.722483 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-13 00:16:51.842170 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 17.6 MB/s eta 0:00:00
2026-02-13 00:16:51.909712 | controller | Installing collected packages: pip
2026-02-13 00:16:51.909845 | controller |   Attempting uninstall: pip
2026-02-13 00:16:51.912155 | controller |     Found existing installation: pip 22.2.2
2026-02-13 00:16:52.080101 | controller |     Uninstalling pip-22.2.2:
2026-02-13 00:16:52.105850 | controller |       Successfully uninstalled pip-22.2.2
2026-02-13 00:16:52.980419 | controller | Successfully installed pip-26.0.1
2026-02-13 00:16:53.136647 | controller | ok: Runtime: 0:00:26.297695
2026-02-13 00:16:53.146316 | 
2026-02-13 00:16:53.146421 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-13 00:16:53.456010 | controller | changed
2026-02-13 00:16:53.464203 | 
2026-02-13 00:16:53.464319 | TASK [Install ansible into virtualenv]
2026-02-13 00:16:54.002872 | controller | Processing ./src/github.com/ansible/ansible
2026-02-13 00:16:54.005413 | controller |   Installing build dependencies: started
2026-02-13 00:17:16.790667 | controller |   Installing build dependencies: finished with status 'done'
2026-02-13 00:17:16.791698 | controller |   Getting requirements to build wheel: started
2026-02-13 00:17:17.572274 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-13 00:17:17.574606 | controller |   Preparing metadata (pyproject.toml): started
2026-02-13 00:17:18.065218 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-13 00:17:18.067401 | 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-13 00:17:18.070145 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-13 00:17:18.532874 | controller | ERROR
2026-02-13 00:17:18.533181 | controller | {
2026-02-13 00:17:18.533246 | controller |   "delta": "0:00:24.439446",
2026-02-13 00:17:18.533285 | controller |   "end": "2026-02-13 00:17:18.148332",
2026-02-13 00:17:18.533318 | controller |   "msg": "non-zero return code",
2026-02-13 00:17:18.533364 | controller |   "rc": 1,
2026-02-13 00:17:18.533398 | controller |   "start": "2026-02-13 00:16:53.708886"
2026-02-13 00:17:18.533429 | controller | }
failure
2026-02-13 00:17:18.535659 | 
2026-02-13 00:17:18.535714 | PLAY RECAP
2026-02-13 00:17:18.535758 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-13 00:17:18.535778 | 
2026-02-13 00:17:18.646377 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:17:18.647976 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:17:19.251437 | 
2026-02-13 00:17:19.251700 | PLAY [all]
2026-02-13 00:17:19.275142 | 
2026-02-13 00:17:19.275256 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-13 00:17:19.725655 | controller | changed: non-zero return code
2026-02-13 00:17:19.732758 | 
2026-02-13 00:17:19.732870 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-13 00:17:19.749405 | controller | skipping: Conditional result was False
2026-02-13 00:17:19.757860 | 
2026-02-13 00:17:19.758091 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-13 00:17:19.783418 | 
2026-02-13 00:17:19.783660 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-13 00:17:19.819283 | 
2026-02-13 00:17:19.819588 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-13 00:17:19.847374 | controller | skipping: Conditional result was False
2026-02-13 00:17:19.857399 | 
2026-02-13 00:17:19.857636 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-13 00:17:19.891634 | 
2026-02-13 00:17:19.891945 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-13 00:17:19.918405 | controller | skipping: Conditional result was False
2026-02-13 00:17:19.925550 | 
2026-02-13 00:17:19.925635 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-13 00:17:19.951141 | controller | skipping: Conditional result was False
2026-02-13 00:17:19.958195 | 
2026-02-13 00:17:19.958287 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-13 00:17:19.983707 | controller | skipping: Conditional result was False
2026-02-13 00:17:20.014159 | 
2026-02-13 00:17:20.014305 | PLAY RECAP
2026-02-13 00:17:20.014355 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:17:20.014376 | 
2026-02-13 00:17:20.170185 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:17:20.171437 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-13 00:17:20.825169 | 
2026-02-13 00:17:20.825296 | PLAY [all:!appliance*]
2026-02-13 00:17:20.855684 | 
2026-02-13 00:17:20.855827 | TASK [unregister the node]
2026-02-13 00:17:21.395683 | controller | skipping: Conditional result was False
2026-02-13 00:17:21.408581 | 
2026-02-13 00:17:21.408736 | TASK [include_role : fetch-output]
2026-02-13 00:17:21.460439 | controller | ok
2026-02-13 00:17:21.495680 | 
2026-02-13 00:17:21.495816 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-13 00:17:21.572432 | controller | skipping: Conditional result was False
2026-02-13 00:17:21.578991 | 
2026-02-13 00:17:21.579101 | TASK [fetch-output : Set log path for single node]
2026-02-13 00:17:21.630055 | controller | ok
2026-02-13 00:17:21.642978 | 
2026-02-13 00:17:21.643110 | LOOP [fetch-output : Ensure local output dirs]
2026-02-13 00:17:22.089908 | controller -> localhost | ok: "/var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/logs"
2026-02-13 00:17:22.329340 | controller -> localhost | changed: "/var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/artifacts"
2026-02-13 00:17:22.554559 | controller -> localhost | changed: "/var/lib/zuul/builds/cd78417f9bef45c38202881df50a86f1/work/docs"
2026-02-13 00:17:22.573059 | 
2026-02-13 00:17:22.573225 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-13 00:17:23.244525 | controller | changed:
2026-02-13 00:17:23.244792 | controller | .d..t...... ./
2026-02-13 00:17:23.244820 | controller | cd+++++++++ controller/
2026-02-13 00:17:23.244854 | controller | changed: All items complete
2026-02-13 00:17:23.244873 | 
2026-02-13 00:17:23.820381 | controller | changed: .d..t...... ./
2026-02-13 00:17:24.319443 | controller | changed: .d..t...... ./
2026-02-13 00:17:24.347447 | 
2026-02-13 00:17:24.347586 | TASK [include_role : fetch-output-openshift]
2026-02-13 00:17:24.373598 | controller | skipping: Conditional result was False
2026-02-13 00:17:24.383305 | 
2026-02-13 00:17:24.383418 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-13 00:17:24.427433 | controller | skipping: Conditional result was False
2026-02-13 00:17:24.439498 | controller | skipping: Conditional result was False
2026-02-13 00:17:24.488688 | 
2026-02-13 00:17:24.488799 | PLAY [localhost]
2026-02-13 00:17:24.503099 | 
2026-02-13 00:17:24.503184 | TASK [Run Zuul manifest role]
2026-02-13 00:17:24.521512 | localhost | ok
2026-02-13 00:17:24.539575 | 
2026-02-13 00:17:24.539675 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-13 00:17:24.912518 | localhost | changed
2026-02-13 00:17:24.923582 | 
2026-02-13 00:17:24.923714 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-13 00:17:24.962452 | localhost | ok
2026-02-13 00:17:24.984728 | 
2026-02-13 00:17:24.984860 | TASK [Set zuul-log-path fact]
2026-02-13 00:17:25.005877 | localhost | ok
2026-02-13 00:17:25.028273 | 
2026-02-13 00:17:25.028397 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:17:25.060917 | localhost | ok
2026-02-13 00:17:25.072632 | 
2026-02-13 00:17:25.072734 | LOOP [Run upload-logs-swift role]
2026-02-13 00:17:25.119984 | localhost | Output suppressed because no_log was given
2026-02-13 00:17:25.160691 | 
2026-02-13 00:17:25.160934 | TASK [Set zuul-log-path fact]
2026-02-13 00:17:25.197312 | localhost | skipping: Conditional result was False
2026-02-13 00:17:25.204087 | 
2026-02-13 00:17:25.204211 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-13 00:17:25.662934 | localhost -> localhost | ok: Runtime: 0:00:00.008299
2026-02-13 00:17:25.713449 | 
2026-02-13 00:17:25.713582 | TASK [upload-logs-swift : Upload logs to swift]