2025-12-20 00:20:56.734920 | Job console starting...
2025-12-20 00:20:56.748062 | Updating repositories
2025-12-20 00:20:56.883931 | Preparing job workspace
2025-12-20 00:21:01.255386 | Running Ansible setup...
2025-12-20 00:21:05.993640 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-20 00:21:06.661005 | 
2025-12-20 00:21:06.661149 | PLAY [localhost]
2025-12-20 00:21:06.670247 | 
2025-12-20 00:21:06.670341 | TASK [Gathering Facts]
2025-12-20 00:21:07.665894 | localhost | ok
2025-12-20 00:21:07.689516 | 
2025-12-20 00:21:07.689711 | TASK [Setup log path fact]
2025-12-20 00:21:07.710369 | localhost | ok
2025-12-20 00:21:07.728071 | 
2025-12-20 00:21:07.728415 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-20 00:21:07.769977 | localhost | ok
2025-12-20 00:21:07.781629 | 
2025-12-20 00:21:07.781779 | TASK [emit-job-header : Print job information]
2025-12-20 00:21:07.822710 | # Job Information
2025-12-20 00:21:07.822907 | Ansible Version: 2.15.12
2025-12-20 00:21:07.822942 | Job: ansible-test-sanity-docker-milestone
2025-12-20 00:21:07.822963 | Pipeline: periodic
2025-12-20 00:21:07.822981 | Executor: ze03.softwarefactory-project.io
2025-12-20 00:21:07.822999 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-20 00:21:07.823021 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2e0/ansible/2e0ba02da8264424ad2cbdff1b89eb36/
2025-12-20 00:21:07.823044 | Event ID: e90b2a34aa9b47e1bd166d0e5d504958
2025-12-20 00:21:07.827054 | 
2025-12-20 00:21:07.827124 | LOOP [emit-job-header : Print node information]
2025-12-20 00:21:07.952318 | localhost | ok:
2025-12-20 00:21:07.952720 | localhost | # Node Information
2025-12-20 00:21:07.952912 | localhost | Inventory Hostname: controller
2025-12-20 00:21:07.952993 | localhost | Hostname: np0005567574
2025-12-20 00:21:07.953066 | localhost | Username: zuul
2025-12-20 00:21:07.953147 | localhost | Distro: Fedora 37
2025-12-20 00:21:07.953975 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-20 00:21:07.954058 | localhost | Region: ca-ymq-1
2025-12-20 00:21:07.954129 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-20 00:21:07.954474 | localhost | Product Name: OpenStack Nova
2025-12-20 00:21:07.954554 | localhost | Interface IP: 162.253.55.187
2025-12-20 00:21:07.967528 | 
2025-12-20 00:21:07.967693 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-20 00:21:08.364539 | localhost -> localhost | changed
2025-12-20 00:21:08.380409 | 
2025-12-20 00:21:08.380613 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-20 00:21:09.506964 | localhost -> localhost | changed
2025-12-20 00:21:09.550426 | 
2025-12-20 00:21:09.550608 | PLAY [all:!appliance*]
2025-12-20 00:21:09.573437 | 
2025-12-20 00:21:09.573525 | TASK [include_role : start-zuul-console]
2025-12-20 00:21:09.596287 | controller | ok
2025-12-20 00:21:09.614764 | 
2025-12-20 00:21:09.614856 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-20 00:21:09.988217 | controller | ok
2025-12-20 00:21:10.014228 | 
2025-12-20 00:21:10.014427 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-20 00:21:31.006168 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-20 00:21:31.013846 | 
2025-12-20 00:21:31.013949 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-20 00:21:31.550330 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.567350 | 
2025-12-20 00:21:31.567566 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-20 00:21:31.597741 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.606066 | 
2025-12-20 00:21:31.606165 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-20 00:21:31.632019 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.639499 | 
2025-12-20 00:21:31.639690 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-20 00:21:31.667122 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.675296 | 
2025-12-20 00:21:31.675376 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-20 00:21:31.700691 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.707818 | 
2025-12-20 00:21:31.707891 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-20 00:21:31.733216 | controller | skipping: Conditional result was False
2025-12-20 00:21:31.745220 | 
2025-12-20 00:21:31.745297 | TASK [Disable Fedora Modular]
2025-12-20 00:21:31.999833 | controller | changed
2025-12-20 00:21:32.010492 | 
2025-12-20 00:21:32.010620 | TASK [Enable EPEL]
2025-12-20 00:21:32.037094 | controller | skipping: Conditional result was False
2025-12-20 00:21:32.048913 | 
2025-12-20 00:21:32.049192 | TASK [Register the RHEL node]
2025-12-20 00:21:32.603655 | 
2025-12-20 00:21:32.603958 | TASK [Show the subscription-manager status]
2025-12-20 00:21:33.159643 | controller | skipping: Conditional result was False
2025-12-20 00:21:33.174812 | 
2025-12-20 00:21:33.175060 | TASK [Enable EPEL on RHEL]
2025-12-20 00:21:33.267994 | controller | skipping: Conditional result was False
2025-12-20 00:21:33.277107 | 
2025-12-20 00:21:33.277214 | TASK [Install git and tox]
2025-12-20 00:22:33.123324 | controller | changed
2025-12-20 00:22:33.131294 | 
2025-12-20 00:22:33.131381 | TASK [include_role : prepare-workspace]
2025-12-20 00:22:33.166207 | controller | ok
2025-12-20 00:22:33.190824 | 
2025-12-20 00:22:33.191009 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-20 00:22:33.429589 | controller | ok
2025-12-20 00:22:33.437265 | 
2025-12-20 00:22:33.437390 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-20 00:22:45.847442 | controller | Output suppressed because no_log was given
2025-12-20 00:22:45.857652 | 
2025-12-20 00:22:45.857761 | TASK [include_role : prepare-workspace-openshift]
2025-12-20 00:22:45.872890 | controller | skipping: Conditional result was False
2025-12-20 00:22:45.896195 | 
2025-12-20 00:22:45.896291 | PLAY [all:!appliance]
2025-12-20 00:22:45.912182 | 
2025-12-20 00:22:45.912271 | TASK [Run add-build-sshkey role (RSA)]
2025-12-20 00:22:45.943339 | controller | ok
2025-12-20 00:22:45.963623 | 
2025-12-20 00:22:45.963778 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-20 00:22:46.254480 | controller -> localhost | ok
2025-12-20 00:22:46.261663 | 
2025-12-20 00:22:46.261786 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-20 00:22:46.287611 | controller | ok
2025-12-20 00:22:46.308020 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-20 00:22:46.319405 | 
2025-12-20 00:22:46.319567 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-20 00:22:46.837403 | controller -> localhost | Generating public/private rsa key pair.
2025-12-20 00:22:46.837602 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_rsa.
2025-12-20 00:22:46.837633 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_rsa.pub.
2025-12-20 00:22:46.837656 | controller -> localhost | The key fingerprint is:
2025-12-20 00:22:46.837677 | controller -> localhost | SHA256:0ny+oZxqDJvzBVGsW59IpQwXmlz5Fw2dQugeW9JoRj4 zuul-build-sshkey
2025-12-20 00:22:46.837698 | controller -> localhost | The key's randomart image is:
2025-12-20 00:22:46.837718 | controller -> localhost | +---[RSA 2048]----+
2025-12-20 00:22:46.837778 | controller -> localhost | |       .+o oo+ . |
2025-12-20 00:22:46.837802 | controller -> localhost | |     ..=+ + o +  |
2025-12-20 00:22:46.837823 | controller -> localhost | |      == B o o   |
2025-12-20 00:22:46.837843 | controller -> localhost | |      .+= E +    |
2025-12-20 00:22:46.837862 | controller -> localhost | |      o+S*.O     |
2025-12-20 00:22:46.837894 | controller -> localhost | |    . .o.o=      |
2025-12-20 00:22:46.837918 | controller -> localhost | |     =  . o      |
2025-12-20 00:22:46.837941 | controller -> localhost | |    + oo o o     |
2025-12-20 00:22:46.837961 | controller -> localhost | |     +o.+ .      |
2025-12-20 00:22:46.837983 | controller -> localhost | +----[SHA256]-----+
2025-12-20 00:22:46.838027 | controller -> localhost | ok: Runtime: 0:00:00.033379
2025-12-20 00:22:46.844666 | 
2025-12-20 00:22:46.844767 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-20 00:22:46.864619 | controller | ok
2025-12-20 00:22:46.876580 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-20 00:22:46.886102 | 
2025-12-20 00:22:46.886231 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-20 00:22:46.900227 | controller | skipping: Conditional result was False
2025-12-20 00:22:46.908951 | 
2025-12-20 00:22:46.909089 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-20 00:22:47.379886 | controller | changed
2025-12-20 00:22:47.388301 | 
2025-12-20 00:22:47.388429 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-20 00:22:47.613920 | controller | ok
2025-12-20 00:22:47.620358 | 
2025-12-20 00:22:47.620428 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-20 00:22:48.233321 | controller | changed
2025-12-20 00:22:48.240158 | 
2025-12-20 00:22:48.240283 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-20 00:22:48.881831 | controller | changed
2025-12-20 00:22:48.897953 | 
2025-12-20 00:22:48.898202 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-20 00:22:48.927686 | controller | skipping: Conditional result was False
2025-12-20 00:22:48.941844 | 
2025-12-20 00:22:48.942037 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-20 00:22:49.326057 | controller -> localhost | changed
2025-12-20 00:22:49.337771 | 
2025-12-20 00:22:49.337869 | TASK [add-build-sshkey : Add back temp key]
2025-12-20 00:22:49.669025 | controller -> localhost | Identity added: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_rsa (zuul-build-sshkey)
2025-12-20 00:22:49.669511 | controller -> localhost | ok: Runtime: 0:00:00.013484
2025-12-20 00:22:49.684649 | 
2025-12-20 00:22:49.684908 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-20 00:22:50.064927 | controller | ok
2025-12-20 00:22:50.077622 | 
2025-12-20 00:22:50.077836 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-20 00:22:50.104613 | controller | skipping: Conditional result was False
2025-12-20 00:22:50.121313 | 
2025-12-20 00:22:50.121472 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-20 00:22:50.154364 | controller | ok
2025-12-20 00:22:50.175882 | 
2025-12-20 00:22:50.176048 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-20 00:22:50.447316 | controller -> localhost | ok
2025-12-20 00:22:50.458086 | 
2025-12-20 00:22:50.458224 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-20 00:22:50.495099 | controller | ok
2025-12-20 00:22:50.513168 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-20 00:22:50.523655 | 
2025-12-20 00:22:50.523820 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-20 00:22:50.845991 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-20 00:22:50.846228 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_ecdsa.
2025-12-20 00:22:50.846273 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_ecdsa.pub.
2025-12-20 00:22:50.846323 | controller -> localhost | The key fingerprint is:
2025-12-20 00:22:50.846354 | controller -> localhost | SHA256:tojOH+G+f/Nuo4OLlDOdklT8uYxnU8uz/NghtyHm9k8 zuul-build-sshkey
2025-12-20 00:22:50.846378 | controller -> localhost | The key's randomart image is:
2025-12-20 00:22:50.846403 | controller -> localhost | +---[ECDSA 521]---+
2025-12-20 00:22:50.846426 | controller -> localhost | |                 |
2025-12-20 00:22:50.846449 | controller -> localhost | |       .         |
2025-12-20 00:22:50.846472 | controller -> localhost | |        o        |
2025-12-20 00:22:50.846496 | controller -> localhost | |       . . .     |
2025-12-20 00:22:50.846518 | controller -> localhost | |      o S o .    |
2025-12-20 00:22:50.846540 | controller -> localhost | |     + B = + .   |
2025-12-20 00:22:50.846562 | controller -> localhost | |    . @ =.* B + E|
2025-12-20 00:22:50.846584 | controller -> localhost | |   o o *.o+=+O = |
2025-12-20 00:22:50.846605 | controller -> localhost | |    o.=ooo.OB+=..|
2025-12-20 00:22:50.846626 | controller -> localhost | +----[SHA256]-----+
2025-12-20 00:22:50.846686 | controller -> localhost | ok: Runtime: 0:00:00.008852
2025-12-20 00:22:50.855912 | 
2025-12-20 00:22:50.856026 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-20 00:22:50.886130 | controller | ok
2025-12-20 00:22:50.894382 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-20 00:22:50.904058 | 
2025-12-20 00:22:50.904159 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-20 00:22:50.928545 | controller | skipping: Conditional result was False
2025-12-20 00:22:50.934917 | 
2025-12-20 00:22:50.934993 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-20 00:22:51.207550 | controller | changed
2025-12-20 00:22:51.270155 | 
2025-12-20 00:22:51.270321 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-20 00:22:51.493155 | controller | ok
2025-12-20 00:22:51.507971 | 
2025-12-20 00:22:51.508265 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-20 00:22:52.133940 | controller | changed
2025-12-20 00:22:52.149148 | 
2025-12-20 00:22:52.149404 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-20 00:22:52.770475 | controller | changed
2025-12-20 00:22:52.776414 | 
2025-12-20 00:22:52.776483 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-20 00:22:52.800124 | controller | skipping: Conditional result was False
2025-12-20 00:22:52.808092 | 
2025-12-20 00:22:52.808180 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-20 00:22:53.056508 | controller -> localhost | changed
2025-12-20 00:22:53.071224 | 
2025-12-20 00:22:53.071333 | TASK [add-build-sshkey : Add back temp key]
2025-12-20 00:22:53.383382 | controller -> localhost | Identity added: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/2e0ba02da8264424ad2cbdff1b89eb36_id_ecdsa (zuul-build-sshkey)
2025-12-20 00:22:53.383678 | controller -> localhost | ok: Runtime: 0:00:00.012713
2025-12-20 00:22:53.391083 | 
2025-12-20 00:22:53.391162 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-20 00:22:53.594751 | controller | ok
2025-12-20 00:22:53.601986 | 
2025-12-20 00:22:53.602076 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-20 00:22:53.647417 | controller | skipping: Conditional result was False
2025-12-20 00:22:53.674937 | 
2025-12-20 00:22:53.675088 | TASK [include_role : remove-zuul-sshkey]
2025-12-20 00:22:53.691322 | controller | skipping: Conditional result was False
2025-12-20 00:22:53.706415 | 
2025-12-20 00:22:53.706586 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-20 00:22:53.935852 | controller | ok: "logs"
2025-12-20 00:22:53.936112 | controller | ok: All items complete
2025-12-20 00:22:53.936142 | 
2025-12-20 00:22:54.132011 | controller | ok: "artifacts"
2025-12-20 00:22:54.339592 | controller | ok: "docs"
2025-12-20 00:22:54.349617 | 
2025-12-20 00:22:54.349799 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-20 00:22:54.593640 | controller | changed: "logs"
2025-12-20 00:22:54.796171 | controller | changed: "artifacts"
2025-12-20 00:22:54.989107 | controller | changed: "docs"
2025-12-20 00:22:55.031277 | 
2025-12-20 00:22:55.031398 | PLAY RECAP
2025-12-20 00:22:55.031502 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-20 00:22:55.031542 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-20 00:22:55.031561 | 
2025-12-20 00:22:55.157770 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-20 00:22:55.158715 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-20 00:22:55.834640 | 
2025-12-20 00:22:55.834781 | PLAY [all]
2025-12-20 00:22:55.859698 | 
2025-12-20 00:22:55.859881 | TASK [Install binary dependencies]
2025-12-20 00:22:55.914420 | controller | ok
2025-12-20 00:22:55.946906 | 
2025-12-20 00:22:55.947141 | TASK [bindep : Include find tasks]
2025-12-20 00:22:55.981089 | controller | ok
2025-12-20 00:22:55.989433 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-20 00:22:55.996578 | 
2025-12-20 00:22:55.996669 | TASK [bindep : Look for bindep.txt]
2025-12-20 00:22:56.337327 | controller | ok
2025-12-20 00:22:56.354829 | 
2025-12-20 00:22:56.355017 | TASK [bindep : Define bindep_file fact]
2025-12-20 00:22:56.380581 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.389104 | 
2025-12-20 00:22:56.389221 | TASK [bindep : Look for other-requirements.txt]
2025-12-20 00:22:56.604630 | controller | ok
2025-12-20 00:22:56.611066 | 
2025-12-20 00:22:56.611201 | TASK [bindep : Define bindep_file fact]
2025-12-20 00:22:56.636232 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.643070 | 
2025-12-20 00:22:56.643176 | TASK [bindep : Look for bindep fallback file]
2025-12-20 00:22:56.667797 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.676653 | 
2025-12-20 00:22:56.676827 | TASK [bindep : Define bindep_file fact]
2025-12-20 00:22:56.701925 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.708698 | 
2025-12-20 00:22:56.708793 | TASK [bindep : Include bindep tasks]
2025-12-20 00:22:56.733445 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.740387 | 
2025-12-20 00:22:56.740464 | TASK [bindep : Include install tasks]
2025-12-20 00:22:56.765163 | controller | skipping: Conditional result was False
2025-12-20 00:22:56.772216 | 
2025-12-20 00:22:56.772325 | LOOP [bindep : Include package tasks]
2025-12-20 00:22:56.838123 | 
2025-12-20 00:22:56.838286 | TASK [Run test-setup role]
2025-12-20 00:22:56.860719 | controller | ok
2025-12-20 00:22:56.878853 | 
2025-12-20 00:22:56.878952 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-20 00:22:57.081285 | controller | ok
2025-12-20 00:22:57.087619 | 
2025-12-20 00:22:57.087722 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-20 00:22:57.622420 | controller | skipping: Conditional result was False
2025-12-20 00:22:57.659638 | 
2025-12-20 00:22:57.659804 | PLAY RECAP
2025-12-20 00:22:57.659865 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-20 00:22:57.659899 | 
2025-12-20 00:22:57.820510 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-20 00:22:57.821777 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-20 00:22:58.468528 | 
2025-12-20 00:22:58.468669 | PLAY [controller]
2025-12-20 00:22:58.490628 | 
2025-12-20 00:22:58.490812 | TASK [Create the /root directory]
2025-12-20 00:22:58.888367 | controller | ok
2025-12-20 00:22:58.894455 | 
2025-12-20 00:22:58.894532 | TASK [Install glibc-langpack-en]
2025-12-20 00:23:02.785944 | controller | ok: Nothing to do
2025-12-20 00:23:02.798308 | 
2025-12-20 00:23:02.798436 | TASK [Ensure controller directory exists]
2025-12-20 00:23:03.011864 | controller | changed
2025-12-20 00:23:03.025708 | 
2025-12-20 00:23:03.025926 | TASK [Install container runtime]
2025-12-20 00:23:03.093026 | controller | ok
2025-12-20 00:23:03.146337 | 
2025-12-20 00:23:03.146510 | LOOP [ensure-podman : Find distribution installation]
2025-12-20 00:23:03.194046 | controller | ok: "/var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-20 00:23:03.204497 | controller | included: /var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-20 00:23:03.215458 | 
2025-12-20 00:23:03.215622 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-20 00:24:10.031348 | controller | changed
2025-12-20 00:24:10.052806 | 
2025-12-20 00:24:10.053025 | TASK [ensure-podman : Fetch podman version]
2025-12-20 00:24:10.606854 | controller | Client:       Podman Engine
2025-12-20 00:24:10.606950 | controller | Version:      4.6.2
2025-12-20 00:24:10.606996 | controller | API Version:  4.6.2
2025-12-20 00:24:10.607039 | controller | Go Version:   go1.19.12
2025-12-20 00:24:10.607097 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-20 00:24:10.607141 | controller | OS/Arch:      linux/amd64
2025-12-20 00:24:11.103307 | controller | ok: Runtime: 0:00:00.182996
2025-12-20 00:24:11.112821 | 
2025-12-20 00:24:11.112969 | TASK [ensure-podman : Print podman version installed]
2025-12-20 00:24:11.146694 | Podman version: Client:       Podman Engine
2025-12-20 00:24:11.146925 | Version:      4.6.2
2025-12-20 00:24:11.146963 | API Version:  4.6.2
2025-12-20 00:24:11.146991 | Go Version:   go1.19.12
2025-12-20 00:24:11.147016 | Built:        Mon Aug 28 19:38:31 2023
2025-12-20 00:24:11.147041 | OS/Arch:      linux/amd64
2025-12-20 00:24:11.155652 | 
2025-12-20 00:24:11.155856 | TASK [ensure-podman : Validate podman engine]
2025-12-20 00:24:11.699258 | controller | skipping: Conditional result was False
2025-12-20 00:24:11.706025 | 
2025-12-20 00:24:11.706109 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-20 00:24:11.730480 | controller | skipping: Conditional result was False
2025-12-20 00:24:11.741376 | 
2025-12-20 00:24:11.741472 | TASK [Ensure python3.8 is present]
2025-12-20 00:24:11.755322 | controller | skipping: Conditional result was False
2025-12-20 00:24:11.762073 | 
2025-12-20 00:24:11.762156 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-20 00:24:11.782970 | controller | ok
2025-12-20 00:24:11.801399 | 
2025-12-20 00:24:11.801486 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-20 00:24:13.155977 | controller | ok: Nothing to do
2025-12-20 00:24:13.164630 | 
2025-12-20 00:24:13.164886 | TASK [our-ensure-python : Also install python3-devel]
2025-12-20 00:24:21.608081 | controller | changed
2025-12-20 00:24:21.619526 | 
2025-12-20 00:24:21.619604 | TASK [Run ensure-virtualenv role]
2025-12-20 00:24:21.640216 | controller | ok
2025-12-20 00:24:21.661121 | 
2025-12-20 00:24:21.661274 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-20 00:24:21.874699 | controller | /usr/bin/virtualenv
2025-12-20 00:24:22.194023 | controller | ok: Runtime: 0:00:00.004980
2025-12-20 00:24:22.200556 | 
2025-12-20 00:24:22.200645 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-20 00:24:22.228620 | controller | skipping: Conditional result was False
2025-12-20 00:24:22.229119 | controller | ok: All items complete
2025-12-20 00:24:22.229148 | 
2025-12-20 00:24:22.248554 | 
2025-12-20 00:24:22.248712 | TASK [Find the full path of the Python interpreter]
2025-12-20 00:24:22.501924 | controller | /usr/bin/python3
2025-12-20 00:24:22.814129 | controller | ok
2025-12-20 00:24:22.827977 | 
2025-12-20 00:24:22.828159 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-20 00:24:23.610923 | controller | created virtual environment CPython3.11.0.final.0-64 in 415ms
2025-12-20 00:24:23.626236 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-20 00:24:23.626270 | 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-12-20 00:24:23.626278 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-20 00:24:23.626291 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-20 00:24:23.890264 | controller | changed
2025-12-20 00:24:23.910064 | 
2025-12-20 00:24:23.910251 | TASK [Set selinux package]
2025-12-20 00:24:23.935363 | controller | ok
2025-12-20 00:24:23.941514 | 
2025-12-20 00:24:23.941581 | TASK [Set selinux package (Fedora)]
2025-12-20 00:24:23.972644 | controller | ok
2025-12-20 00:24:23.979642 | 
2025-12-20 00:24:23.979708 | TASK [Install selinux into virtualenv]
2025-12-20 00:25:01.451343 | controller | Collecting selinux-please-lie-to-me
2025-12-20 00:25:13.716187 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-20 00:25:14.026440 | controller | Collecting setuptools<50.0.0
2025-12-20 00:25:14.030721 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-20 00:25:14.069903 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.6 MB/s eta 0:00:00
2025-12-20 00:25:14.151204 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-20 00:25:14.151412 | controller |   Attempting uninstall: setuptools
2025-12-20 00:25:14.153820 | controller |     Found existing installation: setuptools 62.6.0
2025-12-20 00:25:14.212471 | controller |     Uninstalling setuptools-62.6.0:
2025-12-20 00:25:14.220730 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-20 00:25:14.562364 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-20 00:25:26.083535 | controller |
2025-12-20 00:25:26.163319 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-20 00:25:26.163360 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-20 00:25:26.551037 | controller | ok: Runtime: 0:01:01.890896
2025-12-20 00:25:26.557399 | 
2025-12-20 00:25:26.557499 | TASK [Install pytest-forked into virtualenv]
2025-12-20 00:25:38.328550 | controller | Collecting pytest-forked
2025-12-20 00:25:50.576754 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-20 00:25:50.623699 | controller | Collecting py
2025-12-20 00:25:50.628023 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-20 00:25:50.649899 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.1 MB/s eta 0:00:00
2025-12-20 00:25:50.761229 | controller | Collecting pytest>=3.10
2025-12-20 00:25:50.765309 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-20 00:25:50.786581 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 22.4 MB/s eta 0:00:00
2025-12-20 00:25:50.830755 | controller | Collecting iniconfig>=1.0.1
2025-12-20 00:25:50.834032 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-20 00:25:50.879209 | controller | Collecting packaging>=22
2025-12-20 00:25:50.883265 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-20 00:25:50.890848 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.3 MB/s eta 0:00:00
2025-12-20 00:25:50.927335 | controller | Collecting pluggy<2,>=1.5
2025-12-20 00:25:50.930737 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-20 00:25:50.985119 | controller | Collecting pygments>=2.7.2
2025-12-20 00:25:50.991768 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-20 00:25:51.012666 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 65.7 MB/s eta 0:00:00
2025-12-20 00:25:51.082019 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-20 00:25:52.132774 | 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
2025-12-20 00:25:52.141335 | controller |
2025-12-20 00:25:52.207150 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-20 00:25:52.207195 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-20 00:25:52.602363 | controller | ok: Runtime: 0:00:25.440303
2025-12-20 00:25:52.608461 | 
2025-12-20 00:25:52.608541 | TASK [Update pip]
2025-12-20 00:25:53.133220 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-20 00:26:12.429527 | controller | Collecting pip
2025-12-20 00:26:24.622938 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-20 00:26:24.669574 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 41.4 MB/s eta 0:00:00
2025-12-20 00:26:24.733519 | controller | Installing collected packages: pip
2025-12-20 00:26:24.733688 | controller |   Attempting uninstall: pip
2025-12-20 00:26:24.735804 | controller |     Found existing installation: pip 22.2.2
2025-12-20 00:26:24.873434 | controller |     Uninstalling pip-22.2.2:
2025-12-20 00:26:24.888927 | controller |       Successfully uninstalled pip-22.2.2
2025-12-20 00:26:25.673533 | controller | Successfully installed pip-25.3
2025-12-20 00:26:26.157351 | controller | ok: Runtime: 0:00:32.912308
2025-12-20 00:26:26.163797 | 
2025-12-20 00:26:26.163891 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-20 00:26:26.392030 | controller | changed
2025-12-20 00:26:26.402711 | 
2025-12-20 00:26:26.402852 | TASK [Install ansible into virtualenv]
2025-12-20 00:26:26.891373 | controller | Processing ./src/github.com/ansible/ansible
2025-12-20 00:26:26.894640 | controller |   Installing build dependencies: started
2025-12-20 00:26:49.550327 | controller |   Installing build dependencies: finished with status 'done'
2025-12-20 00:26:49.551430 | controller |   Getting requirements to build wheel: started
2025-12-20 00:26:50.263239 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-20 00:26:50.264728 | controller |   Preparing metadata (pyproject.toml): started
2025-12-20 00:26:50.717661 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-20 00:26:50.724539 | 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-12-20 00:26:50.728598 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-20 00:26:50.958004 | controller | ERROR
2025-12-20 00:26:50.958308 | controller | {
2025-12-20 00:26:50.958383 | controller |   "delta": "0:00:24.177382",
2025-12-20 00:26:50.958431 | controller |   "end": "2025-12-20 00:26:50.789691",
2025-12-20 00:26:50.958472 | controller |   "msg": "non-zero return code",
2025-12-20 00:26:50.958532 | controller |   "rc": 1,
2025-12-20 00:26:50.958573 | controller |   "start": "2025-12-20 00:26:26.612309"
2025-12-20 00:26:50.958613 | controller | }
failure
2025-12-20 00:26:50.961381 | 
2025-12-20 00:26:50.961485 | PLAY RECAP
2025-12-20 00:26:50.961580 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-20 00:26:50.961628 | 
2025-12-20 00:26:51.113704 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-20 00:26:51.115313 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-20 00:26:51.769085 | 
2025-12-20 00:26:51.769332 | PLAY [all]
2025-12-20 00:26:51.802958 | 
2025-12-20 00:26:51.803154 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-20 00:26:52.031098 | controller | changed: non-zero return code
2025-12-20 00:26:52.037504 | 
2025-12-20 00:26:52.037612 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-20 00:26:52.052925 | controller | skipping: Conditional result was False
2025-12-20 00:26:52.067123 | 
2025-12-20 00:26:52.067272 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-20 00:26:52.089437 | 
2025-12-20 00:26:52.089616 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-20 00:26:52.110393 | 
2025-12-20 00:26:52.110572 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-20 00:26:52.125215 | controller | skipping: Conditional result was False
2025-12-20 00:26:52.133534 | 
2025-12-20 00:26:52.133684 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-20 00:26:52.154935 | 
2025-12-20 00:26:52.155105 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-20 00:26:52.168764 | controller | skipping: Conditional result was False
2025-12-20 00:26:52.175879 | 
2025-12-20 00:26:52.176009 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-20 00:26:52.190216 | controller | skipping: Conditional result was False
2025-12-20 00:26:52.198040 | 
2025-12-20 00:26:52.198166 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-20 00:26:52.211931 | controller | skipping: Conditional result was False
2025-12-20 00:26:52.240803 | 
2025-12-20 00:26:52.240956 | PLAY RECAP
2025-12-20 00:26:52.241019 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-20 00:26:52.241047 | 
2025-12-20 00:26:52.371953 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-20 00:26:52.373163 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-20 00:26:53.019446 | 
2025-12-20 00:26:53.019562 | PLAY [all:!appliance*]
2025-12-20 00:26:53.040942 | 
2025-12-20 00:26:53.041048 | TASK [unregister the node]
2025-12-20 00:26:53.570872 | controller | skipping: Conditional result was False
2025-12-20 00:26:53.580491 | 
2025-12-20 00:26:53.580627 | TASK [include_role : fetch-output]
2025-12-20 00:26:53.632990 | controller | ok
2025-12-20 00:26:53.654073 | 
2025-12-20 00:26:53.654214 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-20 00:26:53.709588 | controller | skipping: Conditional result was False
2025-12-20 00:26:53.716493 | 
2025-12-20 00:26:53.716615 | TASK [fetch-output : Set log path for single node]
2025-12-20 00:26:53.758143 | controller | ok
2025-12-20 00:26:53.764911 | 
2025-12-20 00:26:53.765010 | LOOP [fetch-output : Ensure local output dirs]
2025-12-20 00:26:54.234156 | controller -> localhost | ok: "/var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/logs"
2025-12-20 00:26:54.545445 | controller -> localhost | changed: "/var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/artifacts"
2025-12-20 00:26:54.782611 | controller -> localhost | changed: "/var/lib/zuul/builds/2e0ba02da8264424ad2cbdff1b89eb36/work/docs"
2025-12-20 00:26:54.800983 | 
2025-12-20 00:26:54.801203 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-20 00:26:55.510766 | controller | changed:
2025-12-20 00:26:55.510991 | controller | .d..t...... ./
2025-12-20 00:26:55.511019 | controller | cd+++++++++ controller/
2025-12-20 00:26:55.511050 | controller | changed: All items complete
2025-12-20 00:26:55.511069 | 
2025-12-20 00:26:56.063280 | controller | changed: .d..t...... ./
2025-12-20 00:26:56.575969 | controller | changed: .d..t...... ./
2025-12-20 00:26:56.593965 | 
2025-12-20 00:26:56.594120 | TASK [include_role : fetch-output-openshift]
2025-12-20 00:26:56.608609 | controller | skipping: Conditional result was False
2025-12-20 00:26:56.615339 | 
2025-12-20 00:26:56.615412 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-20 00:26:56.644648 | controller | skipping: Conditional result was False
2025-12-20 00:26:56.655711 | controller | skipping: Conditional result was False
2025-12-20 00:26:56.700447 | 
2025-12-20 00:26:56.700621 | PLAY [localhost]
2025-12-20 00:26:56.716244 | 
2025-12-20 00:26:56.716404 | TASK [Run Zuul manifest role]
2025-12-20 00:26:56.739160 | localhost | ok
2025-12-20 00:26:56.760517 | 
2025-12-20 00:26:56.760665 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-20 00:26:57.214540 | localhost | changed
2025-12-20 00:26:57.223089 | 
2025-12-20 00:26:57.223543 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-20 00:26:57.256715 | localhost | ok
2025-12-20 00:26:57.269538 | 
2025-12-20 00:26:57.269639 | TASK [Set zuul-log-path fact]
2025-12-20 00:26:57.291742 | localhost | ok
2025-12-20 00:26:57.313985 | 
2025-12-20 00:26:57.314115 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-20 00:26:57.356144 | localhost | ok
2025-12-20 00:26:57.368496 | 
2025-12-20 00:26:57.368592 | LOOP [Run upload-logs-swift role]
2025-12-20 00:26:57.406187 | localhost | Output suppressed because no_log was given
2025-12-20 00:26:57.443314 | 
2025-12-20 00:26:57.443615 | TASK [Set zuul-log-path fact]
2025-12-20 00:26:57.479424 | localhost | skipping: Conditional result was False
2025-12-20 00:26:57.488962 | 
2025-12-20 00:26:57.489100 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-20 00:26:57.924924 | localhost -> localhost | ok: Runtime: 0:00:00.004676
2025-12-20 00:26:57.929665 | 
2025-12-20 00:26:57.929753 | TASK [upload-logs-swift : Upload logs to swift]