2025-11-11 00:20:49.141370 | Job console starting...
2025-11-11 00:20:49.153845 | Updating repositories
2025-11-11 00:20:49.341120 | Preparing job workspace
2025-11-11 00:20:53.450354 | Running Ansible setup...
2025-11-11 00:20:58.637454 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-11 00:20:59.327858 | 
2025-11-11 00:20:59.328015 | PLAY [localhost]
2025-11-11 00:20:59.336374 | 
2025-11-11 00:20:59.336442 | TASK [Gathering Facts]
2025-11-11 00:21:00.433922 | localhost | ok
2025-11-11 00:21:00.466558 | 
2025-11-11 00:21:00.466798 | TASK [Setup log path fact]
2025-11-11 00:21:00.488344 | localhost | ok
2025-11-11 00:21:00.507361 | 
2025-11-11 00:21:00.507480 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-11 00:21:00.541785 | localhost | ok
2025-11-11 00:21:00.558140 | 
2025-11-11 00:21:00.558286 | TASK [emit-job-header : Print job information]
2025-11-11 00:21:00.603783 | # Job Information
2025-11-11 00:21:00.604251 | Ansible Version: 2.15.12
2025-11-11 00:21:00.604352 | Job: ansible-test-sanity-docker-devel
2025-11-11 00:21:00.604401 | Pipeline: periodic
2025-11-11 00:21:00.604442 | Executor: ze04.softwarefactory-project.io
2025-11-11 00:21:00.604482 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-11 00:21:00.604528 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/038/ansible/038a6ea223ac4fd7b09c4bd0f5a9947e/
2025-11-11 00:21:00.604570 | Event ID: 227e4e6828f94fb3a69b0e687d5dfdf5
2025-11-11 00:21:00.612572 | 
2025-11-11 00:21:00.612748 | LOOP [emit-job-header : Print node information]
2025-11-11 00:21:00.727726 | localhost | ok:
2025-11-11 00:21:00.728037 | localhost | # Node Information
2025-11-11 00:21:00.728109 | localhost | Inventory Hostname: controller
2025-11-11 00:21:00.728160 | localhost | Hostname: np0005517401
2025-11-11 00:21:00.728209 | localhost | Username: zuul
2025-11-11 00:21:00.728265 | localhost | Distro: Fedora 37
2025-11-11 00:21:00.728312 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-11-11 00:21:00.728357 | localhost | Region: ca-ymq-1
2025-11-11 00:21:00.728402 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-11 00:21:00.728446 | localhost | Product Name: OpenStack Nova
2025-11-11 00:21:00.728494 | localhost | Interface IP: 162.253.55.200
2025-11-11 00:21:00.753458 | 
2025-11-11 00:21:00.753806 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-11 00:21:01.230179 | localhost -> localhost | changed
2025-11-11 00:21:01.236591 | 
2025-11-11 00:21:01.236725 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-11 00:21:02.181458 | localhost -> localhost | changed
2025-11-11 00:21:02.211069 | 
2025-11-11 00:21:02.211256 | PLAY [all:!appliance*]
2025-11-11 00:21:02.237121 | 
2025-11-11 00:21:02.237294 | TASK [include_role : start-zuul-console]
2025-11-11 00:21:02.262567 | controller | ok
2025-11-11 00:21:02.285160 | 
2025-11-11 00:21:02.285338 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-11 00:21:02.672610 | controller | ok
2025-11-11 00:21:02.683525 | 
2025-11-11 00:21:02.683622 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-11 00:21:03.744406 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-11 00:21:03.759468 | 
2025-11-11 00:21:03.759651 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-11 00:21:04.310791 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.325252 | 
2025-11-11 00:21:04.325408 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-11 00:21:04.362911 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.379369 | 
2025-11-11 00:21:04.379715 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-11 00:21:04.409952 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.425843 | 
2025-11-11 00:21:04.426075 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-11 00:21:04.468059 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.483238 | 
2025-11-11 00:21:04.483448 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-11 00:21:04.513763 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.530806 | 
2025-11-11 00:21:04.531171 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-11 00:21:04.560771 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.600472 | 
2025-11-11 00:21:04.600672 | TASK [Disable Fedora Modular]
2025-11-11 00:21:04.864827 | controller | changed
2025-11-11 00:21:04.878429 | 
2025-11-11 00:21:04.878582 | TASK [Enable EPEL]
2025-11-11 00:21:04.906848 | controller | skipping: Conditional result was False
2025-11-11 00:21:04.921434 | 
2025-11-11 00:21:04.921616 | TASK [Register the RHEL node]
2025-11-11 00:21:05.499416 | 
2025-11-11 00:21:05.499813 | TASK [Show the subscription-manager status]
2025-11-11 00:21:06.092969 | controller | skipping: Conditional result was False
2025-11-11 00:21:06.103788 | 
2025-11-11 00:21:06.103904 | TASK [Enable EPEL on RHEL]
2025-11-11 00:21:06.663087 | controller | skipping: Conditional result was False
2025-11-11 00:21:06.677390 | 
2025-11-11 00:21:06.677559 | TASK [Install git and tox]
2025-11-11 00:22:48.071407 | controller | changed
2025-11-11 00:22:48.077536 | 
2025-11-11 00:22:48.077602 | TASK [include_role : prepare-workspace]
2025-11-11 00:22:48.110851 | controller | ok
2025-11-11 00:22:48.138172 | 
2025-11-11 00:22:48.138262 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-11 00:22:48.381710 | controller | ok
2025-11-11 00:22:48.400423 | 
2025-11-11 00:22:48.400631 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-11 00:23:00.338789 | controller | Output suppressed because no_log was given
2025-11-11 00:23:00.354007 | 
2025-11-11 00:23:00.354149 | TASK [include_role : prepare-workspace-openshift]
2025-11-11 00:23:00.380500 | controller | skipping: Conditional result was False
2025-11-11 00:23:00.414205 | 
2025-11-11 00:23:00.414461 | PLAY [all:!appliance]
2025-11-11 00:23:00.437230 | 
2025-11-11 00:23:00.437350 | TASK [Run add-build-sshkey role (RSA)]
2025-11-11 00:23:00.470073 | controller | ok
2025-11-11 00:23:00.486879 | 
2025-11-11 00:23:00.486961 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-11 00:23:00.776596 | controller -> localhost | ok
2025-11-11 00:23:00.784021 | 
2025-11-11 00:23:00.784103 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-11 00:23:00.817395 | controller | ok
2025-11-11 00:23:00.832803 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-11 00:23:00.840394 | 
2025-11-11 00:23:00.840459 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-11 00:23:01.365850 | controller -> localhost | Generating public/private rsa key pair.
2025-11-11 00:23:01.366265 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_rsa.
2025-11-11 00:23:01.366335 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_rsa.pub.
2025-11-11 00:23:01.366388 | controller -> localhost | The key fingerprint is:
2025-11-11 00:23:01.366436 | controller -> localhost | SHA256:n0UbQYrpUrVY/SDRJelBItTV0bq6ik6bd6YEqHQ/gKA zuul-build-sshkey
2025-11-11 00:23:01.366482 | controller -> localhost | The key's randomart image is:
2025-11-11 00:23:01.366525 | controller -> localhost | +---[RSA 2048]----+
2025-11-11 00:23:01.366569 | controller -> localhost | |       .o.=B*+oo |
2025-11-11 00:23:01.366614 | controller -> localhost | |         Bo+*o. .|
2025-11-11 00:23:01.366656 | controller -> localhost | |  .     = ooo+ . |
2025-11-11 00:23:01.366784 | controller -> localhost | | . . . +   ..oo  |
2025-11-11 00:23:01.366840 | controller -> localhost | |E   o = S   o  . |
2025-11-11 00:23:01.366903 | controller -> localhost | |   . o + o o  .  |
2025-11-11 00:23:01.366962 | controller -> localhost | |    .   + +  .   |
2025-11-11 00:23:01.367007 | controller -> localhost | |       . *. +    |
2025-11-11 00:23:01.367049 | controller -> localhost | |       .=.o=..   |
2025-11-11 00:23:01.367097 | controller -> localhost | +----[SHA256]-----+
2025-11-11 00:23:01.367203 | controller -> localhost | ok: Runtime: 0:00:00.122971
2025-11-11 00:23:01.383577 | 
2025-11-11 00:23:01.383779 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-11 00:23:01.425323 | controller | ok
2025-11-11 00:23:01.447802 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-11 00:23:01.460581 | 
2025-11-11 00:23:01.460708 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-11 00:23:01.497712 | controller | skipping: Conditional result was False
2025-11-11 00:23:01.507566 | 
2025-11-11 00:23:01.507702 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-11 00:23:01.967794 | controller | changed
2025-11-11 00:23:01.980920 | 
2025-11-11 00:23:01.981060 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-11 00:23:02.234334 | controller | ok
2025-11-11 00:23:02.250296 | 
2025-11-11 00:23:02.250510 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-11 00:23:02.922976 | controller | changed
2025-11-11 00:23:02.931031 | 
2025-11-11 00:23:02.931114 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-11 00:23:03.632987 | controller | changed
2025-11-11 00:23:03.646934 | 
2025-11-11 00:23:03.647071 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-11 00:23:03.686011 | controller | skipping: Conditional result was False
2025-11-11 00:23:03.700630 | 
2025-11-11 00:23:03.700849 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-11 00:23:04.184106 | controller -> localhost | changed
2025-11-11 00:23:04.196194 | 
2025-11-11 00:23:04.196270 | TASK [add-build-sshkey : Add back temp key]
2025-11-11 00:23:04.543016 | controller -> localhost | Identity added: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_rsa (zuul-build-sshkey)
2025-11-11 00:23:04.543700 | controller -> localhost | ok: Runtime: 0:00:00.021853
2025-11-11 00:23:04.560047 | 
2025-11-11 00:23:04.560194 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-11 00:23:04.943317 | controller | ok
2025-11-11 00:23:04.949077 | 
2025-11-11 00:23:04.949149 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-11 00:23:04.995236 | controller | skipping: Conditional result was False
2025-11-11 00:23:05.008762 | 
2025-11-11 00:23:05.008866 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-11 00:23:05.042072 | controller | ok
2025-11-11 00:23:05.062479 | 
2025-11-11 00:23:05.062608 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-11 00:23:05.336248 | controller -> localhost | ok
2025-11-11 00:23:05.355728 | 
2025-11-11 00:23:05.355892 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-11 00:23:05.401254 | controller | ok
2025-11-11 00:23:05.427719 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-11 00:23:05.436656 | 
2025-11-11 00:23:05.436775 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-11 00:23:05.772752 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-11 00:23:05.773247 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_ecdsa.
2025-11-11 00:23:05.773313 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_ecdsa.pub.
2025-11-11 00:23:05.773378 | controller -> localhost | The key fingerprint is:
2025-11-11 00:23:05.773425 | controller -> localhost | SHA256:QYlMUnvwQLQyewPT+MplqrKWo0yGCifh5QX/CD1Ojok zuul-build-sshkey
2025-11-11 00:23:05.773470 | controller -> localhost | The key's randomart image is:
2025-11-11 00:23:05.773514 | controller -> localhost | +---[ECDSA 521]---+
2025-11-11 00:23:05.773558 | controller -> localhost | |    .*B...       |
2025-11-11 00:23:05.773600 | controller -> localhost | |     +oB.        |
2025-11-11 00:23:05.773674 | controller -> localhost | |   .* + +        |
2025-11-11 00:23:05.773812 | controller -> localhost | |    +B . .       |
2025-11-11 00:23:05.773857 | controller -> localhost | |.  o.** S        |
2025-11-11 00:23:05.773899 | controller -> localhost | |o.+.O*+.         |
2025-11-11 00:23:05.773940 | controller -> localhost | |+Eo+++ .         |
2025-11-11 00:23:05.773981 | controller -> localhost | |B* .             |
2025-11-11 00:23:05.774021 | controller -> localhost | |*+o              |
2025-11-11 00:23:05.774061 | controller -> localhost | +----[SHA256]-----+
2025-11-11 00:23:05.774179 | controller -> localhost | ok: Runtime: 0:00:00.009985
2025-11-11 00:23:05.789963 | 
2025-11-11 00:23:05.790112 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-11 00:23:05.842521 | controller | ok
2025-11-11 00:23:05.864113 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-11 00:23:05.880668 | 
2025-11-11 00:23:05.880795 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-11 00:23:05.918066 | controller | skipping: Conditional result was False
2025-11-11 00:23:05.931316 | 
2025-11-11 00:23:05.931427 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-11 00:23:06.198002 | controller | changed
2025-11-11 00:23:06.212951 | 
2025-11-11 00:23:06.213117 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-11 00:23:06.463763 | controller | ok
2025-11-11 00:23:06.478042 | 
2025-11-11 00:23:06.478247 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-11 00:23:07.139538 | controller | changed
2025-11-11 00:23:07.146446 | 
2025-11-11 00:23:07.146519 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-11 00:23:07.806230 | controller | changed
2025-11-11 00:23:07.875005 | 
2025-11-11 00:23:07.875172 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-11 00:23:07.910618 | controller | skipping: Conditional result was False
2025-11-11 00:23:07.919119 | 
2025-11-11 00:23:07.919212 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-11 00:23:08.177746 | controller -> localhost | changed
2025-11-11 00:23:08.190191 | 
2025-11-11 00:23:08.190292 | TASK [add-build-sshkey : Add back temp key]
2025-11-11 00:23:08.500444 | controller -> localhost | Identity added: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/038a6ea223ac4fd7b09c4bd0f5a9947e_id_ecdsa (zuul-build-sshkey)
2025-11-11 00:23:08.500709 | controller -> localhost | ok: Runtime: 0:00:00.014669
2025-11-11 00:23:08.507568 | 
2025-11-11 00:23:08.507634 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-11 00:23:08.722371 | controller | ok
2025-11-11 00:23:08.728159 | 
2025-11-11 00:23:08.728226 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-11 00:23:08.753480 | controller | skipping: Conditional result was False
2025-11-11 00:23:08.765138 | 
2025-11-11 00:23:08.765227 | TASK [include_role : remove-zuul-sshkey]
2025-11-11 00:23:08.790493 | controller | skipping: Conditional result was False
2025-11-11 00:23:08.797129 | 
2025-11-11 00:23:08.797199 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-11 00:23:09.023581 | controller | ok: "logs"
2025-11-11 00:23:09.023882 | controller | ok: All items complete
2025-11-11 00:23:09.023911 | 
2025-11-11 00:23:09.787185 | controller | ok: "artifacts"
2025-11-11 00:23:09.980897 | controller | ok: "docs"
2025-11-11 00:23:10.001735 | 
2025-11-11 00:23:10.001884 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-11 00:23:10.252742 | controller | changed: "logs"
2025-11-11 00:23:10.448062 | controller | changed: "artifacts"
2025-11-11 00:23:10.646104 | controller | changed: "docs"
2025-11-11 00:23:10.713792 | 
2025-11-11 00:23:10.713946 | PLAY RECAP
2025-11-11 00:23:10.714008 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-11 00:23:10.714046 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-11 00:23:10.714071 | 
2025-11-11 00:23:10.866716 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-11 00:23:10.867800 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-11 00:23:11.515471 | 
2025-11-11 00:23:11.515747 | PLAY [all]
2025-11-11 00:23:11.548960 | 
2025-11-11 00:23:11.549170 | TASK [Install binary dependencies]
2025-11-11 00:23:11.634602 | controller | ok
2025-11-11 00:23:11.669061 | 
2025-11-11 00:23:11.669307 | TASK [bindep : Include find tasks]
2025-11-11 00:23:11.714847 | controller | ok
2025-11-11 00:23:11.727926 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-11 00:23:11.738413 | 
2025-11-11 00:23:11.738575 | TASK [bindep : Look for bindep.txt]
2025-11-11 00:23:12.114575 | controller | ok
2025-11-11 00:23:12.123144 | 
2025-11-11 00:23:12.123232 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:23:12.139911 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.149839 | 
2025-11-11 00:23:12.149941 | TASK [bindep : Look for other-requirements.txt]
2025-11-11 00:23:12.355609 | controller | ok
2025-11-11 00:23:12.363048 | 
2025-11-11 00:23:12.363138 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:23:12.390454 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.398958 | 
2025-11-11 00:23:12.399048 | TASK [bindep : Look for bindep fallback file]
2025-11-11 00:23:12.425811 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.435872 | 
2025-11-11 00:23:12.435966 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:23:12.462557 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.471471 | 
2025-11-11 00:23:12.471571 | TASK [bindep : Include bindep tasks]
2025-11-11 00:23:12.498506 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.507159 | 
2025-11-11 00:23:12.507245 | TASK [bindep : Include install tasks]
2025-11-11 00:23:12.533590 | controller | skipping: Conditional result was False
2025-11-11 00:23:12.542325 | 
2025-11-11 00:23:12.542409 | LOOP [bindep : Include package tasks]
2025-11-11 00:23:12.605303 | 
2025-11-11 00:23:12.605557 | TASK [Run test-setup role]
2025-11-11 00:23:12.632111 | controller | ok
2025-11-11 00:23:12.655714 | 
2025-11-11 00:23:12.655887 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-11 00:23:12.884120 | controller | ok
2025-11-11 00:23:12.891759 | 
2025-11-11 00:23:12.891823 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-11 00:23:13.431663 | controller | skipping: Conditional result was False
2025-11-11 00:23:13.490286 | 
2025-11-11 00:23:13.490499 | PLAY RECAP
2025-11-11 00:23:13.490573 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-11 00:23:13.490602 | 
2025-11-11 00:23:13.659709 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-11 00:23:13.660718 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-11 00:23:14.241118 | 
2025-11-11 00:23:14.241270 | PLAY [controller]
2025-11-11 00:23:14.261870 | 
2025-11-11 00:23:14.261962 | TASK [Create the /root directory]
2025-11-11 00:23:14.661999 | controller | ok
2025-11-11 00:23:14.674837 | 
2025-11-11 00:23:14.674989 | TASK [Install glibc-langpack-en]
2025-11-11 00:23:18.598366 | controller | ok: Nothing to do
2025-11-11 00:23:18.613279 | 
2025-11-11 00:23:18.613428 | TASK [Ensure controller directory exists]
2025-11-11 00:23:18.831510 | controller | changed
2025-11-11 00:23:18.846103 | 
2025-11-11 00:23:18.846246 | TASK [Install container runtime]
2025-11-11 00:23:18.928745 | controller | ok
2025-11-11 00:23:18.989562 | 
2025-11-11 00:23:18.989738 | LOOP [ensure-podman : Find distribution installation]
2025-11-11 00:23:19.017593 | controller | ok: "/var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-11 00:23:19.032914 | controller | included: /var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-11 00:23:19.039239 | 
2025-11-11 00:23:19.039303 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-11 00:24:25.958809 | controller | changed
2025-11-11 00:24:25.973325 | 
2025-11-11 00:24:25.973475 | TASK [ensure-podman : Fetch podman version]
2025-11-11 00:24:26.568832 | controller | Client:       Podman Engine
2025-11-11 00:24:26.568934 | controller | Version:      4.6.2
2025-11-11 00:24:26.568979 | controller | API Version:  4.6.2
2025-11-11 00:24:26.569035 | controller | Go Version:   go1.19.12
2025-11-11 00:24:26.569089 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-11 00:24:26.569132 | controller | OS/Arch:      linux/amd64
2025-11-11 00:24:27.020021 | controller | ok: Runtime: 0:00:00.211318
2025-11-11 00:24:27.034972 | 
2025-11-11 00:24:27.035141 | TASK [ensure-podman : Print podman version installed]
2025-11-11 00:24:27.093169 | Podman version: Client:       Podman Engine
2025-11-11 00:24:27.093477 | Version:      4.6.2
2025-11-11 00:24:27.093545 | API Version:  4.6.2
2025-11-11 00:24:27.093591 | Go Version:   go1.19.12
2025-11-11 00:24:27.093630 | Built:        Mon Aug 28 19:38:31 2023
2025-11-11 00:24:27.093670 | OS/Arch:      linux/amd64
2025-11-11 00:24:27.104419 | 
2025-11-11 00:24:27.104522 | TASK [ensure-podman : Validate podman engine]
2025-11-11 00:24:27.655328 | controller | skipping: Conditional result was False
2025-11-11 00:24:27.669042 | 
2025-11-11 00:24:27.669182 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-11 00:24:27.686238 | controller | skipping: Conditional result was False
2025-11-11 00:24:27.710194 | 
2025-11-11 00:24:27.710390 | TASK [Ensure python3.8 is present]
2025-11-11 00:24:27.728845 | controller | skipping: Conditional result was False
2025-11-11 00:24:27.748799 | 
2025-11-11 00:24:27.748968 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-11 00:24:27.772673 | controller | ok
2025-11-11 00:24:27.801792 | 
2025-11-11 00:24:27.801910 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-11 00:24:29.229018 | controller | ok: Nothing to do
2025-11-11 00:24:29.237229 | 
2025-11-11 00:24:29.237337 | TASK [our-ensure-python : Also install python3-devel]
2025-11-11 00:24:39.664829 | controller | changed
2025-11-11 00:24:39.689084 | 
2025-11-11 00:24:39.689241 | TASK [Run ensure-virtualenv role]
2025-11-11 00:24:39.713319 | controller | ok
2025-11-11 00:24:39.744484 | 
2025-11-11 00:24:39.744650 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-11 00:24:39.978557 | controller | /usr/bin/virtualenv
2025-11-11 00:24:40.287324 | controller | ok: Runtime: 0:00:00.004930
2025-11-11 00:24:40.300405 | 
2025-11-11 00:24:40.300531 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-11 00:24:40.334204 | controller | skipping: Conditional result was False
2025-11-11 00:24:40.334666 | controller | ok: All items complete
2025-11-11 00:24:40.334757 | 
2025-11-11 00:24:40.361497 | 
2025-11-11 00:24:40.361661 | TASK [Find the full path of the Python interpreter]
2025-11-11 00:24:40.640250 | controller | /usr/bin/python3
2025-11-11 00:24:40.944457 | controller | ok
2025-11-11 00:24:40.957124 | 
2025-11-11 00:24:40.957255 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-11 00:24:41.829976 | controller | created virtual environment CPython3.11.0.final.0-64 in 492ms
2025-11-11 00:24:41.845735 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-11 00:24:41.845775 | 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)
2025-11-11 00:24:41.845783 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-11 00:24:41.845798 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-11 00:24:42.004913 | controller | changed
2025-11-11 00:24:42.018402 | 
2025-11-11 00:24:42.018531 | TASK [Set selinux package]
2025-11-11 00:24:42.058210 | controller | ok
2025-11-11 00:24:42.070411 | 
2025-11-11 00:24:42.070541 | TASK [Set selinux package (Fedora)]
2025-11-11 00:24:42.119663 | controller | ok
2025-11-11 00:24:42.131788 | 
2025-11-11 00:24:42.131957 | TASK [Install selinux into virtualenv]
2025-11-11 00:24:55.754791 | controller | Collecting selinux-please-lie-to-me
2025-11-11 00:25:07.977288 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-11 00:25:08.293774 | controller | Collecting setuptools<50.0.0
2025-11-11 00:25:08.299334 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-11 00:25:08.335352 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.1 MB/s eta 0:00:00
2025-11-11 00:25:08.415084 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-11 00:25:08.415157 | controller |   Attempting uninstall: setuptools
2025-11-11 00:25:08.417666 | controller |     Found existing installation: setuptools 62.6.0
2025-11-11 00:25:08.477522 | controller |     Uninstalling setuptools-62.6.0:
2025-11-11 00:25:08.485259 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-11 00:25:08.837051 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-11 00:25:21.304351 | controller |
2025-11-11 00:25:21.391595 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-11 00:25:21.391648 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-11 00:25:21.723818 | controller | ok: Runtime: 0:00:39.008028
2025-11-11 00:25:21.736775 | 
2025-11-11 00:25:21.736913 | TASK [Install pytest-forked into virtualenv]
2025-11-11 00:25:33.525498 | controller | Collecting pytest-forked
2025-11-11 00:25:43.853311 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-11 00:25:43.904663 | controller | Collecting py
2025-11-11 00:25:43.912639 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-11 00:25:43.930598 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.7 MB/s eta 0:00:00
2025-11-11 00:25:44.040444 | controller | Collecting pytest>=3.10
2025-11-11 00:25:44.050935 | controller |   Downloading pytest-9.0.0-py3-none-any.whl (373 kB)
2025-11-11 00:25:44.068828 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.4/373.4 kB 25.9 MB/s eta 0:00:00
2025-11-11 00:25:44.155263 | controller | Collecting iniconfig>=1.0.1
2025-11-11 00:25:44.161254 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-11 00:25:44.203060 | controller | Collecting packaging>=22
2025-11-11 00:25:44.209450 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-11 00:25:44.216058 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 16.6 MB/s eta 0:00:00
2025-11-11 00:25:44.247979 | controller | Collecting pluggy<2,>=1.5
2025-11-11 00:25:44.253591 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-11 00:25:44.323712 | controller | Collecting pygments>=2.7.2
2025-11-11 00:25:44.327763 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-11 00:25:44.364188 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.0 MB/s eta 0:00:00
2025-11-11 00:25:44.434489 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-11 00:25:45.490572 | 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.0 pytest-forked-1.6.0
2025-11-11 00:25:45.499673 | controller |
2025-11-11 00:25:45.582899 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-11 00:25:45.582931 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-11 00:25:45.817893 | controller | ok: Runtime: 0:00:23.604874
2025-11-11 00:25:45.831278 | 
2025-11-11 00:25:45.831412 | TASK [Update pip]
2025-11-11 00:25:46.430223 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-11 00:25:56.221727 | controller | Collecting pip
2025-11-11 00:26:08.397520 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-11 00:26:08.449197 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.5 MB/s eta 0:00:00
2025-11-11 00:26:08.514518 | controller | Installing collected packages: pip
2025-11-11 00:26:08.514761 | controller |   Attempting uninstall: pip
2025-11-11 00:26:08.516960 | controller |     Found existing installation: pip 22.2.2
2025-11-11 00:26:08.655642 | controller |     Uninstalling pip-22.2.2:
2025-11-11 00:26:08.670917 | controller |       Successfully uninstalled pip-22.2.2
2025-11-11 00:26:09.475476 | controller | Successfully installed pip-25.3
2025-11-11 00:26:09.910015 | controller | ok: Runtime: 0:00:23.450926
2025-11-11 00:26:09.916904 | 
2025-11-11 00:26:09.916974 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-11 00:26:10.152102 | controller | changed
2025-11-11 00:26:10.164104 | 
2025-11-11 00:26:10.164349 | TASK [Install ansible into virtualenv]
2025-11-11 00:26:10.684740 | controller | Processing ./src/github.com/ansible/ansible
2025-11-11 00:26:10.687972 | controller |   Installing build dependencies: started
2025-11-11 00:26:33.282648 | controller |   Installing build dependencies: finished with status 'done'
2025-11-11 00:26:33.283285 | controller |   Getting requirements to build wheel: started
2025-11-11 00:26:34.013447 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-11 00:26:34.014312 | controller |   Preparing metadata (pyproject.toml): started
2025-11-11 00:26:34.462484 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-11 00:26:34.467986 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while.
2025-11-11 00:26:34.471429 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-11 00:26:34.731345 | controller | ERROR
2025-11-11 00:26:34.731595 | controller | {
2025-11-11 00:26:34.731860 | controller |   "delta": "0:00:24.128732",
2025-11-11 00:26:34.731925 | controller |   "end": "2025-11-11 00:26:34.530290",
2025-11-11 00:26:34.731963 | controller |   "msg": "non-zero return code",
2025-11-11 00:26:34.732022 | controller |   "rc": 1,
2025-11-11 00:26:34.732059 | controller |   "start": "2025-11-11 00:26:10.401558"
2025-11-11 00:26:34.732092 | controller | }
failure
2025-11-11 00:26:34.735288 | 
2025-11-11 00:26:34.735391 | PLAY RECAP
2025-11-11 00:26:34.735477 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-11 00:26:34.735520 | 
2025-11-11 00:26:34.888976 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-11 00:26:34.891180 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-11 00:26:35.545225 | 
2025-11-11 00:26:35.545375 | PLAY [all]
2025-11-11 00:26:35.567632 | 
2025-11-11 00:26:35.567767 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-11 00:26:35.842869 | controller | changed: non-zero return code
2025-11-11 00:26:35.856632 | 
2025-11-11 00:26:35.856861 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-11 00:26:35.874779 | controller | skipping: Conditional result was False
2025-11-11 00:26:35.888550 | 
2025-11-11 00:26:35.888749 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-11 00:26:35.921177 | 
2025-11-11 00:26:35.921492 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-11 00:26:35.952210 | 
2025-11-11 00:26:35.952502 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-11 00:26:35.980020 | controller | skipping: Conditional result was False
2025-11-11 00:26:35.991221 | 
2025-11-11 00:26:35.991336 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-11 00:26:36.027336 | 
2025-11-11 00:26:36.027574 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-11 00:26:36.042899 | controller | skipping: Conditional result was False
2025-11-11 00:26:36.053230 | 
2025-11-11 00:26:36.053362 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-11 00:26:36.069513 | controller | skipping: Conditional result was False
2025-11-11 00:26:36.080074 | 
2025-11-11 00:26:36.080202 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-11 00:26:36.095503 | controller | skipping: Conditional result was False
2025-11-11 00:26:36.135347 | 
2025-11-11 00:26:36.135491 | PLAY RECAP
2025-11-11 00:26:36.135537 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-11 00:26:36.135557 | 
2025-11-11 00:26:36.266972 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-11 00:26:36.268011 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-11 00:26:36.886110 | 
2025-11-11 00:26:36.886268 | PLAY [all:!appliance*]
2025-11-11 00:26:36.908950 | 
2025-11-11 00:26:36.909080 | TASK [unregister the node]
2025-11-11 00:26:37.440917 | controller | skipping: Conditional result was False
2025-11-11 00:26:37.454054 | 
2025-11-11 00:26:37.454227 | TASK [include_role : fetch-output]
2025-11-11 00:26:37.506942 | controller | ok
2025-11-11 00:26:37.549905 | 
2025-11-11 00:26:37.550010 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-11 00:26:37.626886 | controller | skipping: Conditional result was False
2025-11-11 00:26:37.636424 | 
2025-11-11 00:26:37.636527 | TASK [fetch-output : Set log path for single node]
2025-11-11 00:26:37.690613 | controller | ok
2025-11-11 00:26:37.698595 | 
2025-11-11 00:26:37.698733 | LOOP [fetch-output : Ensure local output dirs]
2025-11-11 00:26:38.155630 | controller -> localhost | ok: "/var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/logs"
2025-11-11 00:26:38.482044 | controller -> localhost | changed: "/var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/artifacts"
2025-11-11 00:26:38.740193 | controller -> localhost | changed: "/var/lib/zuul/builds/038a6ea223ac4fd7b09c4bd0f5a9947e/work/docs"
2025-11-11 00:26:38.771933 | 
2025-11-11 00:26:38.772181 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-11 00:26:39.543628 | controller | changed:
2025-11-11 00:26:39.544560 | controller | .d..t...... ./
2025-11-11 00:26:39.544625 | controller | cd+++++++++ controller/
2025-11-11 00:26:39.544739 | controller | changed: All items complete
2025-11-11 00:26:39.544808 | 
2025-11-11 00:26:40.090122 | controller | changed: .d..t...... ./
2025-11-11 00:26:40.644193 | controller | changed: .d..t...... ./
2025-11-11 00:26:40.671777 | 
2025-11-11 00:26:40.672090 | TASK [include_role : fetch-output-openshift]
2025-11-11 00:26:40.700307 | controller | skipping: Conditional result was False
2025-11-11 00:26:40.717434 | 
2025-11-11 00:26:40.717650 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-11 00:26:40.768339 | controller | skipping: Conditional result was False
2025-11-11 00:26:40.783106 | controller | skipping: Conditional result was False
2025-11-11 00:26:40.841268 | 
2025-11-11 00:26:40.841505 | PLAY [localhost]
2025-11-11 00:26:40.858242 | 
2025-11-11 00:26:40.858332 | TASK [Run Zuul manifest role]
2025-11-11 00:26:40.890509 | localhost | ok
2025-11-11 00:26:40.908439 | 
2025-11-11 00:26:40.908530 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-11 00:26:41.391442 | localhost | changed
2025-11-11 00:26:41.401669 | 
2025-11-11 00:26:41.401858 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-11 00:26:41.448805 | localhost | ok
2025-11-11 00:26:41.465964 | 
2025-11-11 00:26:41.466113 | TASK [Set zuul-log-path fact]
2025-11-11 00:26:41.490000 | localhost | ok
2025-11-11 00:26:41.515174 | 
2025-11-11 00:26:41.515359 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-11 00:26:41.557220 | localhost | ok
2025-11-11 00:26:41.565239 | 
2025-11-11 00:26:41.565302 | LOOP [Run upload-logs-swift role]
2025-11-11 00:26:41.623554 | localhost | Output suppressed because no_log was given
2025-11-11 00:26:41.670334 | 
2025-11-11 00:26:41.670516 | TASK [Set zuul-log-path fact]
2025-11-11 00:26:41.717412 | localhost | skipping: Conditional result was False
2025-11-11 00:26:41.731535 | 
2025-11-11 00:26:41.731788 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-11 00:26:42.206926 | localhost -> localhost | ok: Runtime: 0:00:00.010644
2025-11-11 00:26:42.217464 | 
2025-11-11 00:26:42.217600 | TASK [upload-logs-swift : Upload logs to swift]