2026-01-01 00:22:25.962693 | Job console starting...
2026-01-01 00:22:25.973360 | Updating repositories
2026-01-01 00:22:26.116961 | Preparing job workspace
2026-01-01 00:22:30.008286 | Running Ansible setup...
2026-01-01 00:22:34.991606 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-01 00:22:35.632280 | 
2026-01-01 00:22:35.632466 | PLAY [localhost]
2026-01-01 00:22:35.641659 | 
2026-01-01 00:22:35.641769 | TASK [Gathering Facts]
2026-01-01 00:22:36.649660 | localhost | ok
2026-01-01 00:22:36.671167 | 
2026-01-01 00:22:36.671332 | TASK [Setup log path fact]
2026-01-01 00:22:36.696903 | localhost | ok
2026-01-01 00:22:36.733208 | 
2026-01-01 00:22:36.733372 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-01 00:22:36.764642 | localhost | ok
2026-01-01 00:22:36.775828 | 
2026-01-01 00:22:36.775935 | TASK [emit-job-header : Print job information]
2026-01-01 00:22:36.828522 | # Job Information
2026-01-01 00:22:36.828895 | Ansible Version: 2.15.12
2026-01-01 00:22:36.828951 | Job: ansible-test-sanity-docker-devel
2026-01-01 00:22:36.828989 | Pipeline: periodic
2026-01-01 00:22:36.829065 | Executor: ze01.softwarefactory-project.io
2026-01-01 00:22:36.829103 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-01 00:22:36.829136 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/165/ansible/165383823b15488486b4b5866630cbf8/
2026-01-01 00:22:36.829167 | Event ID: 60371722dc364a52bdf08c652cb66876
2026-01-01 00:22:36.835148 | 
2026-01-01 00:22:36.835305 | LOOP [emit-job-header : Print node information]
2026-01-01 00:22:36.967182 | localhost | ok:
2026-01-01 00:22:36.967490 | localhost | # Node Information
2026-01-01 00:22:36.967552 | localhost | Inventory Hostname: controller
2026-01-01 00:22:36.967596 | localhost | Hostname: np0005573019
2026-01-01 00:22:36.967638 | localhost | Username: zuul
2026-01-01 00:22:36.967687 | localhost | Distro: Fedora 37
2026-01-01 00:22:36.967727 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-01 00:22:36.967764 | localhost | Region: ca-ymq-1
2026-01-01 00:22:36.967801 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-01 00:22:36.967836 | localhost | Product Name: OpenStack Nova
2026-01-01 00:22:36.967872 | localhost | Interface IP: 162.253.55.200
2026-01-01 00:22:36.988301 | 
2026-01-01 00:22:36.988725 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-01 00:22:37.444559 | localhost -> localhost | changed
2026-01-01 00:22:37.459520 | 
2026-01-01 00:22:37.459685 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-01 00:22:38.456482 | localhost -> localhost | changed
2026-01-01 00:22:38.480783 | 
2026-01-01 00:22:38.480868 | PLAY [all:!appliance*]
2026-01-01 00:22:38.496500 | 
2026-01-01 00:22:38.496668 | TASK [include_role : start-zuul-console]
2026-01-01 00:22:38.517256 | controller | ok
2026-01-01 00:22:38.532010 | 
2026-01-01 00:22:38.532116 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-01 00:22:38.918989 | controller | ok
2026-01-01 00:22:38.930386 | 
2026-01-01 00:22:38.930471 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-01 00:22:39.849360 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-01 00:22:39.855770 | 
2026-01-01 00:22:39.855853 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-01 00:22:40.390003 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.401679 | 
2026-01-01 00:22:40.401786 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-01 00:22:40.438486 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.447760 | 
2026-01-01 00:22:40.447862 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-01 00:22:40.473911 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.484108 | 
2026-01-01 00:22:40.484250 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-01 00:22:40.522368 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.532009 | 
2026-01-01 00:22:40.532230 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-01 00:22:40.558825 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.568298 | 
2026-01-01 00:22:40.568468 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-01 00:22:40.595181 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.613665 | 
2026-01-01 00:22:40.613825 | TASK [Disable Fedora Modular]
2026-01-01 00:22:40.860909 | controller | changed
2026-01-01 00:22:40.867678 | 
2026-01-01 00:22:40.867759 | TASK [Enable EPEL]
2026-01-01 00:22:40.894717 | controller | skipping: Conditional result was False
2026-01-01 00:22:40.906731 | 
2026-01-01 00:22:40.906942 | TASK [Register the RHEL node]
2026-01-01 00:22:41.463729 | 
2026-01-01 00:22:41.464078 | TASK [Show the subscription-manager status]
2026-01-01 00:22:42.053121 | controller | skipping: Conditional result was False
2026-01-01 00:22:42.068243 | 
2026-01-01 00:22:42.068418 | TASK [Enable EPEL on RHEL]
2026-01-01 00:22:42.624672 | controller | skipping: Conditional result was False
2026-01-01 00:22:42.632914 | 
2026-01-01 00:22:42.633028 | TASK [Install git and tox]
2026-01-01 00:24:03.697849 | controller | changed
2026-01-01 00:24:03.714050 | 
2026-01-01 00:24:03.714185 | TASK [include_role : prepare-workspace]
2026-01-01 00:24:03.737943 | controller | ok
2026-01-01 00:24:03.766816 | 
2026-01-01 00:24:03.766943 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-01 00:24:04.009201 | controller | ok
2026-01-01 00:24:04.024333 | 
2026-01-01 00:24:04.024529 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-01 00:24:16.253461 | controller | Output suppressed because no_log was given
2026-01-01 00:24:16.264329 | 
2026-01-01 00:24:16.264460 | TASK [include_role : prepare-workspace-openshift]
2026-01-01 00:24:16.282472 | controller | skipping: Conditional result was False
2026-01-01 00:24:16.305759 | 
2026-01-01 00:24:16.305829 | PLAY [all:!appliance]
2026-01-01 00:24:16.322392 | 
2026-01-01 00:24:16.322466 | TASK [Run add-build-sshkey role (RSA)]
2026-01-01 00:24:16.343352 | controller | ok
2026-01-01 00:24:16.359412 | 
2026-01-01 00:24:16.359550 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-01 00:24:16.589214 | controller -> localhost | ok
2026-01-01 00:24:16.598858 | 
2026-01-01 00:24:16.598984 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-01 00:24:16.624981 | controller | ok
2026-01-01 00:24:16.644697 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-01 00:24:16.652851 | 
2026-01-01 00:24:16.652951 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-01 00:24:17.188410 | controller -> localhost | Generating public/private rsa key pair.
2026-01-01 00:24:17.188615 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_rsa.
2026-01-01 00:24:17.188642 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_rsa.pub.
2026-01-01 00:24:17.188663 | controller -> localhost | The key fingerprint is:
2026-01-01 00:24:17.188682 | controller -> localhost | SHA256:IoPfGwoNLLX9BTFBFV0GU6V2gHlB9mxB4t69pru7v2Y zuul-build-sshkey
2026-01-01 00:24:17.188700 | controller -> localhost | The key's randomart image is:
2026-01-01 00:24:17.188718 | controller -> localhost | +---[RSA 2048]----+
2026-01-01 00:24:17.188735 | controller -> localhost | |     .=ooooBX++  |
2026-01-01 00:24:17.188753 | controller -> localhost | |       o  +=.* . |
2026-01-01 00:24:17.188770 | controller -> localhost | |  .   .    .+ =  |
2026-01-01 00:24:17.188787 | controller -> localhost | | o +   .   o + . |
2026-01-01 00:24:17.188803 | controller -> localhost | |. = + . S   . . .|
2026-01-01 00:24:17.188831 | controller -> localhost | | . + = o        .|
2026-01-01 00:24:17.188852 | controller -> localhost | |  . o +        o |
2026-01-01 00:24:17.188871 | controller -> localhost | |   . . o      oE |
2026-01-01 00:24:17.188888 | controller -> localhost | |    . .      *Oo.|
2026-01-01 00:24:17.188907 | controller -> localhost | +----[SHA256]-----+
2026-01-01 00:24:17.188958 | controller -> localhost | ok: Runtime: 0:00:00.098955
2026-01-01 00:24:17.200728 | 
2026-01-01 00:24:17.200800 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-01 00:24:17.230372 | controller | ok
2026-01-01 00:24:17.242109 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-01 00:24:17.251541 | 
2026-01-01 00:24:17.251608 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-01 00:24:17.275903 | controller | skipping: Conditional result was False
2026-01-01 00:24:17.282202 | 
2026-01-01 00:24:17.282268 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-01 00:24:17.713097 | controller | changed
2026-01-01 00:24:17.721954 | 
2026-01-01 00:24:17.722072 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-01 00:24:17.958173 | controller | ok
2026-01-01 00:24:17.975525 | 
2026-01-01 00:24:17.975704 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-01 00:24:18.593390 | controller | changed
2026-01-01 00:24:18.599258 | 
2026-01-01 00:24:18.599321 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-01 00:24:19.212140 | controller | changed
2026-01-01 00:24:19.225003 | 
2026-01-01 00:24:19.225241 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-01 00:24:19.253697 | controller | skipping: Conditional result was False
2026-01-01 00:24:19.268560 | 
2026-01-01 00:24:19.269254 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-01 00:24:19.733962 | controller -> localhost | changed
2026-01-01 00:24:19.746556 | 
2026-01-01 00:24:19.746641 | TASK [add-build-sshkey : Add back temp key]
2026-01-01 00:24:19.997157 | controller -> localhost | Identity added: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_rsa (zuul-build-sshkey)
2026-01-01 00:24:19.997586 | controller -> localhost | ok: Runtime: 0:00:00.007270
2026-01-01 00:24:20.011437 | 
2026-01-01 00:24:20.011583 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-01 00:24:20.346384 | controller | ok
2026-01-01 00:24:20.351930 | 
2026-01-01 00:24:20.352002 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-01 00:24:20.376387 | controller | skipping: Conditional result was False
2026-01-01 00:24:20.388730 | 
2026-01-01 00:24:20.388812 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-01 00:24:20.409497 | controller | ok
2026-01-01 00:24:20.427031 | 
2026-01-01 00:24:20.427158 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-01 00:24:20.663892 | controller -> localhost | ok
2026-01-01 00:24:20.670382 | 
2026-01-01 00:24:20.670456 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-01 00:24:20.691623 | controller | ok
2026-01-01 00:24:20.702267 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-01 00:24:20.708187 | 
2026-01-01 00:24:20.708250 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-01 00:24:21.017828 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-01 00:24:21.018231 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_ecdsa.
2026-01-01 00:24:21.018299 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_ecdsa.pub.
2026-01-01 00:24:21.018364 | controller -> localhost | The key fingerprint is:
2026-01-01 00:24:21.018411 | controller -> localhost | SHA256:AhR6ydAKqXE/Jdn0+tlibcE6HGvauD9SbqI3i4s0MAg zuul-build-sshkey
2026-01-01 00:24:21.018457 | controller -> localhost | The key's randomart image is:
2026-01-01 00:24:21.018501 | controller -> localhost | +---[ECDSA 521]---+
2026-01-01 00:24:21.018544 | controller -> localhost | | ...o=.          |
2026-01-01 00:24:21.018586 | controller -> localhost | |+ .=+.o.         |
2026-01-01 00:24:21.018628 | controller -> localhost | |E+.o=o  .        |
2026-01-01 00:24:21.018670 | controller -> localhost | |+ ..o. . .       |
2026-01-01 00:24:21.018711 | controller -> localhost | |+    .o S o      |
2026-01-01 00:24:21.018751 | controller -> localhost | | o     +.B .     |
2026-01-01 00:24:21.018792 | controller -> localhost | |  o    o@ +      |
2026-01-01 00:24:21.018833 | controller -> localhost | | . o .=*++       |
2026-01-01 00:24:21.018873 | controller -> localhost | |  . ++=Oo.       |
2026-01-01 00:24:21.018914 | controller -> localhost | +----[SHA256]-----+
2026-01-01 00:24:21.019006 | controller -> localhost | ok: Runtime: 0:00:00.014636
2026-01-01 00:24:21.034394 | 
2026-01-01 00:24:21.034533 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-01 00:24:21.076004 | controller | ok
2026-01-01 00:24:21.093494 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-01 00:24:21.105654 | 
2026-01-01 00:24:21.105751 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-01 00:24:21.141117 | controller | skipping: Conditional result was False
2026-01-01 00:24:21.149810 | 
2026-01-01 00:24:21.149907 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-01 00:24:21.434782 | controller | changed
2026-01-01 00:24:21.451822 | 
2026-01-01 00:24:21.452076 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-01 00:24:21.673185 | controller | ok
2026-01-01 00:24:21.683041 | 
2026-01-01 00:24:21.683154 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-01 00:24:22.323127 | controller | changed
2026-01-01 00:24:22.335388 | 
2026-01-01 00:24:22.335521 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-01 00:24:22.982844 | controller | changed
2026-01-01 00:24:23.034726 | 
2026-01-01 00:24:23.034878 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-01 00:24:23.059443 | controller | skipping: Conditional result was False
2026-01-01 00:24:23.068064 | 
2026-01-01 00:24:23.068206 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-01 00:24:23.298349 | controller -> localhost | changed
2026-01-01 00:24:23.323420 | 
2026-01-01 00:24:23.323546 | TASK [add-build-sshkey : Add back temp key]
2026-01-01 00:24:23.626259 | controller -> localhost | Identity added: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/165383823b15488486b4b5866630cbf8_id_ecdsa (zuul-build-sshkey)
2026-01-01 00:24:23.626487 | controller -> localhost | ok: Runtime: 0:00:00.016102
2026-01-01 00:24:23.633680 | 
2026-01-01 00:24:23.633744 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-01 00:24:23.838829 | controller | ok
2026-01-01 00:24:23.847664 | 
2026-01-01 00:24:23.847768 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-01 00:24:23.887077 | controller | skipping: Conditional result was False
2026-01-01 00:24:23.899957 | 
2026-01-01 00:24:23.900139 | TASK [include_role : remove-zuul-sshkey]
2026-01-01 00:24:23.925085 | controller | skipping: Conditional result was False
2026-01-01 00:24:23.932215 | 
2026-01-01 00:24:23.932285 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-01 00:24:24.161252 | controller | ok: "logs"
2026-01-01 00:24:24.161522 | controller | ok: All items complete
2026-01-01 00:24:24.161551 | 
2026-01-01 00:24:24.370274 | controller | ok: "artifacts"
2026-01-01 00:24:24.560609 | controller | ok: "docs"
2026-01-01 00:24:24.581975 | 
2026-01-01 00:24:24.582182 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-01 00:24:24.841510 | controller | changed: "logs"
2026-01-01 00:24:25.033766 | controller | changed: "artifacts"
2026-01-01 00:24:25.226518 | controller | changed: "docs"
2026-01-01 00:24:25.285230 | 
2026-01-01 00:24:25.285415 | PLAY RECAP
2026-01-01 00:24:25.285482 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-01 00:24:25.285519 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-01 00:24:25.285545 | 
2026-01-01 00:24:25.481741 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-01 00:24:25.483473 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-01 00:24:26.357054 | 
2026-01-01 00:24:26.357192 | PLAY [all]
2026-01-01 00:24:26.383200 | 
2026-01-01 00:24:26.383355 | TASK [Install binary dependencies]
2026-01-01 00:24:26.457358 | controller | ok
2026-01-01 00:24:26.484818 | 
2026-01-01 00:24:26.484987 | TASK [bindep : Include find tasks]
2026-01-01 00:24:26.549236 | controller | ok
2026-01-01 00:24:26.559930 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-01 00:24:26.568919 | 
2026-01-01 00:24:26.569009 | TASK [bindep : Look for bindep.txt]
2026-01-01 00:24:26.948841 | controller | ok
2026-01-01 00:24:26.965220 | 
2026-01-01 00:24:26.965458 | TASK [bindep : Define bindep_file fact]
2026-01-01 00:24:26.993203 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.003492 | 
2026-01-01 00:24:27.003592 | TASK [bindep : Look for other-requirements.txt]
2026-01-01 00:24:27.219855 | controller | ok
2026-01-01 00:24:27.227907 | 
2026-01-01 00:24:27.227998 | TASK [bindep : Define bindep_file fact]
2026-01-01 00:24:27.253095 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.260142 | 
2026-01-01 00:24:27.260213 | TASK [bindep : Look for bindep fallback file]
2026-01-01 00:24:27.285146 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.293641 | 
2026-01-01 00:24:27.293716 | TASK [bindep : Define bindep_file fact]
2026-01-01 00:24:27.318739 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.326207 | 
2026-01-01 00:24:27.326274 | TASK [bindep : Include bindep tasks]
2026-01-01 00:24:27.351269 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.358330 | 
2026-01-01 00:24:27.358408 | TASK [bindep : Include install tasks]
2026-01-01 00:24:27.403639 | controller | skipping: Conditional result was False
2026-01-01 00:24:27.410202 | 
2026-01-01 00:24:27.410274 | LOOP [bindep : Include package tasks]
2026-01-01 00:24:27.476628 | 
2026-01-01 00:24:27.476819 | TASK [Run test-setup role]
2026-01-01 00:24:27.498684 | controller | ok
2026-01-01 00:24:27.516318 | 
2026-01-01 00:24:27.516403 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-01 00:24:27.729359 | controller | ok
2026-01-01 00:24:27.735468 | 
2026-01-01 00:24:27.735528 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-01 00:24:28.270098 | controller | skipping: Conditional result was False
2026-01-01 00:24:28.296972 | 
2026-01-01 00:24:28.297105 | PLAY RECAP
2026-01-01 00:24:28.297150 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-01 00:24:28.297171 | 
2026-01-01 00:24:28.434371 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-01 00:24:28.435275 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-01 00:24:29.037846 | 
2026-01-01 00:24:29.037982 | PLAY [controller]
2026-01-01 00:24:29.058680 | 
2026-01-01 00:24:29.058782 | TASK [Create the /root directory]
2026-01-01 00:24:29.486880 | controller | ok
2026-01-01 00:24:29.501722 | 
2026-01-01 00:24:29.502103 | TASK [Install glibc-langpack-en]
2026-01-01 00:24:33.439918 | controller | ok: Nothing to do
2026-01-01 00:24:33.455121 | 
2026-01-01 00:24:33.455271 | TASK [Ensure controller directory exists]
2026-01-01 00:24:33.677255 | controller | changed
2026-01-01 00:24:33.685423 | 
2026-01-01 00:24:33.685528 | TASK [Install container runtime]
2026-01-01 00:24:33.761387 | controller | ok
2026-01-01 00:24:33.822640 | 
2026-01-01 00:24:33.822784 | LOOP [ensure-podman : Find distribution installation]
2026-01-01 00:24:33.867187 | controller | ok: "/var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-01 00:24:33.893773 | controller | included: /var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-01 00:24:33.908900 | 
2026-01-01 00:24:33.908990 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-01 00:25:39.012415 | controller | changed
2026-01-01 00:25:39.028873 | 
2026-01-01 00:25:39.029286 | TASK [ensure-podman : Fetch podman version]
2026-01-01 00:25:39.582614 | controller | Client:       Podman Engine
2026-01-01 00:25:39.582704 | controller | Version:      4.6.2
2026-01-01 00:25:39.582749 | controller | API Version:  4.6.2
2026-01-01 00:25:39.582791 | controller | Go Version:   go1.19.12
2026-01-01 00:25:39.582844 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-01 00:25:39.582887 | controller | OS/Arch:      linux/amd64
2026-01-01 00:25:40.082521 | controller | ok: Runtime: 0:00:00.196373
2026-01-01 00:25:40.091496 | 
2026-01-01 00:25:40.091614 | TASK [ensure-podman : Print podman version installed]
2026-01-01 00:25:40.126327 | Podman version: Client:       Podman Engine
2026-01-01 00:25:40.126552 | Version:      4.6.2
2026-01-01 00:25:40.126594 | API Version:  4.6.2
2026-01-01 00:25:40.126626 | Go Version:   go1.19.12
2026-01-01 00:25:40.126655 | Built:        Mon Aug 28 19:38:31 2023
2026-01-01 00:25:40.126687 | OS/Arch:      linux/amd64
2026-01-01 00:25:40.134583 | 
2026-01-01 00:25:40.134686 | TASK [ensure-podman : Validate podman engine]
2026-01-01 00:25:40.678878 | controller | skipping: Conditional result was False
2026-01-01 00:25:40.693989 | 
2026-01-01 00:25:40.694249 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-01 00:25:40.721407 | controller | skipping: Conditional result was False
2026-01-01 00:25:40.748412 | 
2026-01-01 00:25:40.748590 | TASK [Ensure python3.8 is present]
2026-01-01 00:25:40.766005 | controller | skipping: Conditional result was False
2026-01-01 00:25:40.780639 | 
2026-01-01 00:25:40.780825 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-01 00:25:40.810309 | controller | ok
2026-01-01 00:25:40.841939 | 
2026-01-01 00:25:40.842085 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-01 00:25:42.247335 | controller | ok: Nothing to do
2026-01-01 00:25:42.260324 | 
2026-01-01 00:25:42.260468 | TASK [our-ensure-python : Also install python3-devel]
2026-01-01 00:25:51.109139 | controller | changed
2026-01-01 00:25:51.141275 | 
2026-01-01 00:25:51.141527 | TASK [Run ensure-virtualenv role]
2026-01-01 00:25:51.171766 | controller | ok
2026-01-01 00:25:51.215507 | 
2026-01-01 00:25:51.215709 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-01 00:25:51.485927 | controller | /usr/bin/virtualenv
2026-01-01 00:25:51.790757 | controller | ok: Runtime: 0:00:00.005010
2026-01-01 00:25:51.803421 | 
2026-01-01 00:25:51.803560 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-01 00:25:51.826421 | controller | skipping: Conditional result was False
2026-01-01 00:25:51.826741 | controller | ok: All items complete
2026-01-01 00:25:51.826777 | 
2026-01-01 00:25:51.854904 | 
2026-01-01 00:25:51.855177 | TASK [Find the full path of the Python interpreter]
2026-01-01 00:25:52.079949 | controller | /usr/bin/python3
2026-01-01 00:25:52.401737 | controller | ok
2026-01-01 00:25:52.409792 | 
2026-01-01 00:25:52.410043 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-01 00:25:53.258643 | controller | created virtual environment CPython3.11.0.final.0-64 in 483ms
2026-01-01 00:25:53.282659 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-01 00:25:53.283067 | 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-01-01 00:25:53.283330 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-01 00:25:53.283562 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-01 00:25:53.448981 | controller | changed
2026-01-01 00:25:53.462426 | 
2026-01-01 00:25:53.462575 | TASK [Set selinux package]
2026-01-01 00:25:53.493182 | controller | ok
2026-01-01 00:25:53.505120 | 
2026-01-01 00:25:53.505293 | TASK [Set selinux package (Fedora)]
2026-01-01 00:25:53.544086 | controller | ok
2026-01-01 00:25:53.556072 | 
2026-01-01 00:25:53.556243 | TASK [Install selinux into virtualenv]
2026-01-01 00:26:19.083469 | controller | Collecting selinux-please-lie-to-me
2026-01-01 00:26:31.328383 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-01 00:26:31.636412 | controller | Collecting setuptools<50.0.0
2026-01-01 00:26:31.640799 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-01 00:26:31.723558 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 10.3 MB/s eta 0:00:00
2026-01-01 00:26:31.803475 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-01 00:26:31.803686 | controller |   Attempting uninstall: setuptools
2026-01-01 00:26:31.806064 | controller |     Found existing installation: setuptools 62.6.0
2026-01-01 00:26:31.865354 | controller |     Uninstalling setuptools-62.6.0:
2026-01-01 00:26:31.873361 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-01 00:26:32.208750 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-01 00:26:43.699701 | controller |
2026-01-01 00:26:43.777760 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-01 00:26:43.777801 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-01 00:26:44.141162 | controller | ok: Runtime: 0:00:49.988179
2026-01-01 00:26:44.152403 | 
2026-01-01 00:26:44.152604 | TASK [Install pytest-forked into virtualenv]
2026-01-01 00:27:19.850586 | controller | Collecting pytest-forked
2026-01-01 00:27:32.063750 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-01 00:27:32.110755 | controller | Collecting py
2026-01-01 00:27:32.115888 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-01 00:27:32.137371 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00
2026-01-01 00:27:32.240124 | controller | Collecting pytest>=3.10
2026-01-01 00:27:32.244348 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-01 00:27:32.262610 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.2 MB/s eta 0:00:00
2026-01-01 00:27:32.300479 | controller | Collecting iniconfig>=1.0.1
2026-01-01 00:27:32.303730 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-01 00:27:32.347522 | controller | Collecting packaging>=22
2026-01-01 00:27:32.350690 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-01 00:27:32.356356 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 17.3 MB/s eta 0:00:00
2026-01-01 00:27:32.389811 | controller | Collecting pluggy<2,>=1.5
2026-01-01 00:27:32.392954 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-01 00:27:32.446371 | controller | Collecting pygments>=2.7.2
2026-01-01 00:27:32.450782 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-01 00:27:32.470108 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 77.3 MB/s eta 0:00:00
2026-01-01 00:27:32.537919 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-01 00:27:33.599600 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-01-01 00:27:33.608332 | controller |
2026-01-01 00:27:33.679531 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-01 00:27:33.679592 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-01 00:27:33.760423 | controller | ok: Runtime: 0:00:49.248367
2026-01-01 00:27:33.773800 | 
2026-01-01 00:27:33.773950 | TASK [Update pip]
2026-01-01 00:27:34.322168 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-01 00:27:44.454543 | controller | Collecting pip
2026-01-01 00:27:56.639350 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-01 00:27:56.701977 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 31.3 MB/s eta 0:00:00
2026-01-01 00:27:56.767769 | controller | Installing collected packages: pip
2026-01-01 00:27:56.767993 | controller |   Attempting uninstall: pip
2026-01-01 00:27:56.770998 | controller |     Found existing installation: pip 22.2.2
2026-01-01 00:27:56.909866 | controller |     Uninstalling pip-22.2.2:
2026-01-01 00:27:56.924877 | controller |       Successfully uninstalled pip-22.2.2
2026-01-01 00:27:57.747640 | controller | Successfully installed pip-25.3
2026-01-01 00:27:57.855209 | controller | ok: Runtime: 0:00:23.802047
2026-01-01 00:27:57.867665 | 
2026-01-01 00:27:57.867796 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-01 00:27:58.102630 | controller | changed
2026-01-01 00:27:58.117968 | 
2026-01-01 00:27:58.118220 | TASK [Install ansible into virtualenv]
2026-01-01 00:27:58.631141 | controller | Processing ./src/github.com/ansible/ansible
2026-01-01 00:27:58.634675 | controller |   Installing build dependencies: started
2026-01-01 00:28:21.522309 | controller |   Installing build dependencies: finished with status 'done'
2026-01-01 00:28:21.523643 | controller |   Getting requirements to build wheel: started
2026-01-01 00:28:22.268429 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-01 00:28:22.269384 | controller |   Preparing metadata (pyproject.toml): started
2026-01-01 00:28:22.726891 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-01 00:28:22.734642 | 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-01-01 00:28:22.740552 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-01 00:28:23.184656 | controller | ERROR
2026-01-01 00:28:23.184824 | controller | {
2026-01-01 00:28:23.184862 | controller |   "delta": "0:00:24.466312",
2026-01-01 00:28:23.184890 | controller |   "end": "2026-01-01 00:28:22.814090",
2026-01-01 00:28:23.184914 | controller |   "msg": "non-zero return code",
2026-01-01 00:28:23.184983 | controller |   "rc": 1,
2026-01-01 00:28:23.185010 | controller |   "start": "2026-01-01 00:27:58.347778"
2026-01-01 00:28:23.185079 | controller | }
failure
2026-01-01 00:28:23.187096 | 
2026-01-01 00:28:23.187171 | PLAY RECAP
2026-01-01 00:28:23.187233 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-01 00:28:23.187270 | 
2026-01-01 00:28:23.320477 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-01 00:28:23.321485 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-01 00:28:23.895408 | 
2026-01-01 00:28:23.895550 | PLAY [all]
2026-01-01 00:28:23.917524 | 
2026-01-01 00:28:23.917650 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-01 00:28:24.199644 | controller | changed: non-zero return code
2026-01-01 00:28:24.208468 | 
2026-01-01 00:28:24.208597 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-01 00:28:24.237803 | controller | skipping: Conditional result was False
2026-01-01 00:28:24.247369 | 
2026-01-01 00:28:24.247473 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-01 00:28:24.287330 | 
2026-01-01 00:28:24.287578 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-01 00:28:24.324778 | 
2026-01-01 00:28:24.325059 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-01 00:28:24.353602 | controller | skipping: Conditional result was False
2026-01-01 00:28:24.364072 | 
2026-01-01 00:28:24.364186 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-01 00:28:24.396593 | 
2026-01-01 00:28:24.396776 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-01 00:28:24.421130 | controller | skipping: Conditional result was False
2026-01-01 00:28:24.429707 | 
2026-01-01 00:28:24.429882 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-01 00:28:24.445725 | controller | skipping: Conditional result was False
2026-01-01 00:28:24.453070 | 
2026-01-01 00:28:24.453155 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-01 00:28:24.476711 | controller | skipping: Conditional result was False
2026-01-01 00:28:24.503391 | 
2026-01-01 00:28:24.503501 | PLAY RECAP
2026-01-01 00:28:24.503547 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-01 00:28:24.503567 | 
2026-01-01 00:28:24.616693 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-01 00:28:24.618470 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-01 00:28:25.249833 | 
2026-01-01 00:28:25.250040 | PLAY [all:!appliance*]
2026-01-01 00:28:25.278820 | 
2026-01-01 00:28:25.279036 | TASK [unregister the node]
2026-01-01 00:28:25.811219 | controller | skipping: Conditional result was False
2026-01-01 00:28:25.817635 | 
2026-01-01 00:28:25.817764 | TASK [include_role : fetch-output]
2026-01-01 00:28:25.857350 | controller | ok
2026-01-01 00:28:25.907864 | 
2026-01-01 00:28:25.908155 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-01 00:28:26.000122 | controller | skipping: Conditional result was False
2026-01-01 00:28:26.010448 | 
2026-01-01 00:28:26.010635 | TASK [fetch-output : Set log path for single node]
2026-01-01 00:28:26.071391 | controller | ok
2026-01-01 00:28:26.081888 | 
2026-01-01 00:28:26.082110 | LOOP [fetch-output : Ensure local output dirs]
2026-01-01 00:28:26.517886 | controller -> localhost | ok: "/var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/logs"
2026-01-01 00:28:26.803709 | controller -> localhost | changed: "/var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/artifacts"
2026-01-01 00:28:27.157617 | controller -> localhost | changed: "/var/lib/zuul/builds/165383823b15488486b4b5866630cbf8/work/docs"
2026-01-01 00:28:27.183842 | 
2026-01-01 00:28:27.184122 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-01 00:28:27.991764 | controller | changed:
2026-01-01 00:28:27.992193 | controller | .d..t...... ./
2026-01-01 00:28:27.992262 | controller | cd+++++++++ controller/
2026-01-01 00:28:27.992337 | controller | changed: All items complete
2026-01-01 00:28:27.992387 | 
2026-01-01 00:28:28.473076 | controller | changed: .d..t...... ./
2026-01-01 00:28:28.924652 | controller | changed: .d..t...... ./
2026-01-01 00:28:28.944788 | 
2026-01-01 00:28:28.944954 | TASK [include_role : fetch-output-openshift]
2026-01-01 00:28:28.980157 | controller | skipping: Conditional result was False
2026-01-01 00:28:28.988067 | 
2026-01-01 00:28:28.988152 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-01 00:28:29.041488 | controller | skipping: Conditional result was False
2026-01-01 00:28:29.053590 | controller | skipping: Conditional result was False
2026-01-01 00:28:29.084460 | 
2026-01-01 00:28:29.084662 | PLAY [localhost]
2026-01-01 00:28:29.098723 | 
2026-01-01 00:28:29.098852 | TASK [Run Zuul manifest role]
2026-01-01 00:28:29.120616 | localhost | ok
2026-01-01 00:28:29.135689 | 
2026-01-01 00:28:29.135774 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-01 00:28:29.563923 | localhost | changed
2026-01-01 00:28:29.571689 | 
2026-01-01 00:28:29.571790 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-01 00:28:29.627985 | localhost | ok
2026-01-01 00:28:29.641435 | 
2026-01-01 00:28:29.641611 | TASK [Set zuul-log-path fact]
2026-01-01 00:28:29.675414 | localhost | ok
2026-01-01 00:28:29.697770 | 
2026-01-01 00:28:29.697958 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-01 00:28:29.742641 | localhost | ok
2026-01-01 00:28:29.755116 | 
2026-01-01 00:28:29.755226 | LOOP [Run upload-logs-swift role]
2026-01-01 00:28:29.805139 | localhost | Output suppressed because no_log was given
2026-01-01 00:28:29.854449 | 
2026-01-01 00:28:29.854823 | TASK [Set zuul-log-path fact]
2026-01-01 00:28:29.892443 | localhost | skipping: Conditional result was False
2026-01-01 00:28:29.899138 | 
2026-01-01 00:28:29.899226 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-01 00:28:30.396920 | localhost -> localhost | ok: Runtime: 0:00:00.008421
2026-01-01 00:28:30.452678 | 
2026-01-01 00:28:30.452843 | TASK [upload-logs-swift : Upload logs to swift]