2025-12-17 00:14:23.510430 | Job console starting...
2025-12-17 00:14:23.601237 | Updating repositories
2025-12-17 00:14:23.739127 | Preparing job workspace
2025-12-17 00:14:29.731193 | Running Ansible setup...
2025-12-17 00:14:35.842975 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-17 00:14:36.481239 | 
2025-12-17 00:14:36.481403 | PLAY [localhost]
2025-12-17 00:14:36.490601 | 
2025-12-17 00:14:36.490709 | TASK [Gathering Facts]
2025-12-17 00:14:37.583648 | localhost | ok
2025-12-17 00:14:37.606105 | 
2025-12-17 00:14:37.606301 | TASK [Setup log path fact]
2025-12-17 00:14:37.629084 | localhost | ok
2025-12-17 00:14:37.649797 | 
2025-12-17 00:14:37.649936 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-17 00:14:37.679647 | localhost | ok
2025-12-17 00:14:37.687666 | 
2025-12-17 00:14:37.687780 | TASK [emit-job-header : Print job information]
2025-12-17 00:14:37.717021 | # Job Information
2025-12-17 00:14:37.717177 | Ansible Version: 2.15.12
2025-12-17 00:14:37.717207 | Job: ansible-test-sanity-docker-devel
2025-12-17 00:14:37.717228 | Pipeline: periodic
2025-12-17 00:14:37.717247 | Executor: ze04.softwarefactory-project.io
2025-12-17 00:14:37.717264 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-17 00:14:37.717284 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/bc7/ansible/bc7baa5104f74b52b7232946b2e149d4/
2025-12-17 00:14:37.717302 | Event ID: e0608ea97fcd4369ae19e395c7921123
2025-12-17 00:14:37.720911 | 
2025-12-17 00:14:37.720980 | LOOP [emit-job-header : Print node information]
2025-12-17 00:14:37.818644 | localhost | ok:
2025-12-17 00:14:37.818893 | localhost | # Node Information
2025-12-17 00:14:37.818936 | localhost | Inventory Hostname: controller
2025-12-17 00:14:37.818957 | localhost | Hostname: np0005562913
2025-12-17 00:14:37.818976 | localhost | Username: zuul
2025-12-17 00:14:37.818998 | localhost | Distro: Fedora 37
2025-12-17 00:14:37.819017 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-17 00:14:37.819034 | localhost | Region: ca-ymq-1
2025-12-17 00:14:37.819050 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-17 00:14:37.819066 | localhost | Product Name: OpenStack Nova
2025-12-17 00:14:37.819083 | localhost | Interface IP: 162.253.55.200
2025-12-17 00:14:37.842461 | 
2025-12-17 00:14:37.842617 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-17 00:14:38.285377 | localhost -> localhost | changed
2025-12-17 00:14:38.291460 | 
2025-12-17 00:14:38.291561 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-17 00:14:39.251474 | localhost -> localhost | changed
2025-12-17 00:14:39.306381 | 
2025-12-17 00:14:39.306580 | PLAY [all:!appliance*]
2025-12-17 00:14:39.329219 | 
2025-12-17 00:14:39.329327 | TASK [include_role : start-zuul-console]
2025-12-17 00:14:39.351079 | controller | ok
2025-12-17 00:14:39.371762 | 
2025-12-17 00:14:39.371868 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-17 00:14:39.742046 | controller | ok
2025-12-17 00:14:39.756121 | 
2025-12-17 00:14:39.756240 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-17 00:14:40.587310 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-17 00:14:40.603120 | 
2025-12-17 00:14:40.603314 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-17 00:14:41.146997 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.161237 | 
2025-12-17 00:14:41.161393 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-17 00:14:41.188232 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.202827 | 
2025-12-17 00:14:41.203029 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-17 00:14:41.231064 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.245588 | 
2025-12-17 00:14:41.245762 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-17 00:14:41.273632 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.290187 | 
2025-12-17 00:14:41.290436 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-17 00:14:41.317624 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.330097 | 
2025-12-17 00:14:41.330226 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-17 00:14:41.357264 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.375018 | 
2025-12-17 00:14:41.375154 | TASK [Disable Fedora Modular]
2025-12-17 00:14:41.652389 | controller | changed
2025-12-17 00:14:41.667413 | 
2025-12-17 00:14:41.667573 | TASK [Enable EPEL]
2025-12-17 00:14:41.686180 | controller | skipping: Conditional result was False
2025-12-17 00:14:41.700336 | 
2025-12-17 00:14:41.700488 | TASK [Register the RHEL node]
2025-12-17 00:14:42.265945 | 
2025-12-17 00:14:42.266216 | TASK [Show the subscription-manager status]
2025-12-17 00:14:42.850925 | controller | skipping: Conditional result was False
2025-12-17 00:14:42.860638 | 
2025-12-17 00:14:42.860784 | TASK [Enable EPEL on RHEL]
2025-12-17 00:14:43.403428 | controller | skipping: Conditional result was False
2025-12-17 00:14:43.417859 | 
2025-12-17 00:14:43.418025 | TASK [Install git and tox]
2025-12-17 00:16:03.767982 | controller | changed
2025-12-17 00:16:03.783534 | 
2025-12-17 00:16:03.783762 | TASK [include_role : prepare-workspace]
2025-12-17 00:16:03.808301 | controller | ok
2025-12-17 00:16:03.837104 | 
2025-12-17 00:16:03.837247 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-17 00:16:04.089261 | controller | ok
2025-12-17 00:16:04.104197 | 
2025-12-17 00:16:04.104340 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-17 00:16:16.497001 | controller | Output suppressed because no_log was given
2025-12-17 00:16:16.508469 | 
2025-12-17 00:16:16.508566 | TASK [include_role : prepare-workspace-openshift]
2025-12-17 00:16:16.524967 | controller | skipping: Conditional result was False
2025-12-17 00:16:16.550485 | 
2025-12-17 00:16:16.550565 | PLAY [all:!appliance]
2025-12-17 00:16:16.566882 | 
2025-12-17 00:16:16.566973 | TASK [Run add-build-sshkey role (RSA)]
2025-12-17 00:16:16.596651 | controller | ok
2025-12-17 00:16:16.615192 | 
2025-12-17 00:16:16.615309 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-17 00:16:16.874412 | controller -> localhost | ok
2025-12-17 00:16:16.883794 | 
2025-12-17 00:16:16.883932 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-17 00:16:16.916890 | controller | ok
2025-12-17 00:16:16.938884 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-17 00:16:16.946927 | 
2025-12-17 00:16:16.947055 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-17 00:16:17.511217 | controller -> localhost | Generating public/private rsa key pair.
2025-12-17 00:16:17.511642 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_rsa.
2025-12-17 00:16:17.511719 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_rsa.pub.
2025-12-17 00:16:17.511754 | controller -> localhost | The key fingerprint is:
2025-12-17 00:16:17.511784 | controller -> localhost | SHA256:U11qXdPCBrEOkco5ujfiWZLFRPV6IDBb6JteESqu2Qk zuul-build-sshkey
2025-12-17 00:16:17.511814 | controller -> localhost | The key's randomart image is:
2025-12-17 00:16:17.511844 | controller -> localhost | +---[RSA 2048]----+
2025-12-17 00:16:17.511871 | controller -> localhost | |      o.o.o.o+..o|
2025-12-17 00:16:17.511901 | controller -> localhost | |      .*. .+ =+.o|
2025-12-17 00:16:17.511929 | controller -> localhost | |     ..oo++ *... |
2025-12-17 00:16:17.511955 | controller -> localhost | |    . oo*o *     |
2025-12-17 00:16:17.511982 | controller -> localhost | |   . . +So. o    |
2025-12-17 00:16:17.512025 | controller -> localhost | |  E . +o.. .     |
2025-12-17 00:16:17.512062 | controller -> localhost | |   = ooo.        |
2025-12-17 00:16:17.512093 | controller -> localhost | |  o o ++o        |
2025-12-17 00:16:17.512122 | controller -> localhost | |     .oo .       |
2025-12-17 00:16:17.512154 | controller -> localhost | +----[SHA256]-----+
2025-12-17 00:16:17.512239 | controller -> localhost | ok: Runtime: 0:00:00.123969
2025-12-17 00:16:17.523403 | 
2025-12-17 00:16:17.523517 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-17 00:16:17.562446 | controller | ok
2025-12-17 00:16:17.581315 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-17 00:16:17.595982 | 
2025-12-17 00:16:17.596146 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-17 00:16:17.624389 | controller | skipping: Conditional result was False
2025-12-17 00:16:17.635431 | 
2025-12-17 00:16:17.635641 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-17 00:16:18.066474 | controller | changed
2025-12-17 00:16:18.082156 | 
2025-12-17 00:16:18.082377 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-17 00:16:18.319442 | controller | ok
2025-12-17 00:16:18.335071 | 
2025-12-17 00:16:18.335350 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-17 00:16:18.973182 | controller | changed
2025-12-17 00:16:18.988091 | 
2025-12-17 00:16:18.988286 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-17 00:16:19.628114 | controller | changed
2025-12-17 00:16:19.634825 | 
2025-12-17 00:16:19.634899 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-17 00:16:19.672572 | controller | skipping: Conditional result was False
2025-12-17 00:16:19.681567 | 
2025-12-17 00:16:19.681814 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-17 00:16:20.125875 | controller -> localhost | changed
2025-12-17 00:16:20.140056 | 
2025-12-17 00:16:20.140207 | TASK [add-build-sshkey : Add back temp key]
2025-12-17 00:16:20.482412 | controller -> localhost | Identity added: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_rsa (zuul-build-sshkey)
2025-12-17 00:16:20.482878 | controller -> localhost | ok: Runtime: 0:00:00.012910
2025-12-17 00:16:20.494258 | 
2025-12-17 00:16:20.494385 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-17 00:16:20.825822 | controller | ok
2025-12-17 00:16:20.833892 | 
2025-12-17 00:16:20.833985 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-17 00:16:20.861515 | controller | skipping: Conditional result was False
2025-12-17 00:16:20.881848 | 
2025-12-17 00:16:20.882010 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-17 00:16:20.916620 | controller | ok
2025-12-17 00:16:20.940141 | 
2025-12-17 00:16:20.940277 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-17 00:16:21.232080 | controller -> localhost | ok
2025-12-17 00:16:21.239061 | 
2025-12-17 00:16:21.239136 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-17 00:16:21.260736 | controller | ok
2025-12-17 00:16:21.272253 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-17 00:16:21.278648 | 
2025-12-17 00:16:21.278744 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-17 00:16:21.558545 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-17 00:16:21.558750 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_ecdsa.
2025-12-17 00:16:21.558779 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_ecdsa.pub.
2025-12-17 00:16:21.558811 | controller -> localhost | The key fingerprint is:
2025-12-17 00:16:21.558831 | controller -> localhost | SHA256:8hfRgj2pKye1uP5C+WBCbsUAMeye8wCeiDAm0YwwfPA zuul-build-sshkey
2025-12-17 00:16:21.558850 | controller -> localhost | The key's randomart image is:
2025-12-17 00:16:21.558868 | controller -> localhost | +---[ECDSA 521]---+
2025-12-17 00:16:21.558885 | controller -> localhost | |=*=o             |
2025-12-17 00:16:21.558902 | controller -> localhost | |oo=o.    o o     |
2025-12-17 00:16:21.558919 | controller -> localhost | | o.E o  . * .    |
2025-12-17 00:16:21.558935 | controller -> localhost | |=.. . o  . +     |
2025-12-17 00:16:21.558952 | controller -> localhost | |B+.+ ...S .      |
2025-12-17 00:16:21.558968 | controller -> localhost | |oo= + == o .     |
2025-12-17 00:16:21.558985 | controller -> localhost | |   = ++o= .      |
2025-12-17 00:16:21.559001 | controller -> localhost | |    . .=..       |
2025-12-17 00:16:21.559017 | controller -> localhost | |     .oo.        |
2025-12-17 00:16:21.559033 | controller -> localhost | +----[SHA256]-----+
2025-12-17 00:16:21.559084 | controller -> localhost | ok: Runtime: 0:00:00.008707
2025-12-17 00:16:21.565750 | 
2025-12-17 00:16:21.565817 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-17 00:16:21.586692 | controller | ok
2025-12-17 00:16:21.595313 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-17 00:16:21.604308 | 
2025-12-17 00:16:21.604378 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-17 00:16:21.629492 | controller | skipping: Conditional result was False
2025-12-17 00:16:21.639891 | 
2025-12-17 00:16:21.640046 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-17 00:16:21.925915 | controller | changed
2025-12-17 00:16:21.933084 | 
2025-12-17 00:16:21.933194 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-17 00:16:22.148126 | controller | ok
2025-12-17 00:16:22.161232 | 
2025-12-17 00:16:22.161392 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-17 00:16:22.782452 | controller | changed
2025-12-17 00:16:22.791524 | 
2025-12-17 00:16:22.791617 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-17 00:16:23.446615 | controller | changed
2025-12-17 00:16:23.509402 | 
2025-12-17 00:16:23.509549 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-17 00:16:23.535940 | controller | skipping: Conditional result was False
2025-12-17 00:16:23.547339 | 
2025-12-17 00:16:23.547487 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-17 00:16:23.788471 | controller -> localhost | changed
2025-12-17 00:16:23.806969 | 
2025-12-17 00:16:23.807080 | TASK [add-build-sshkey : Add back temp key]
2025-12-17 00:16:24.129859 | controller -> localhost | Identity added: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/bc7baa5104f74b52b7232946b2e149d4_id_ecdsa (zuul-build-sshkey)
2025-12-17 00:16:24.130203 | controller -> localhost | ok: Runtime: 0:00:00.006905
2025-12-17 00:16:24.139520 | 
2025-12-17 00:16:24.139622 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-17 00:16:24.343402 | controller | ok
2025-12-17 00:16:24.355537 | 
2025-12-17 00:16:24.355712 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-17 00:16:24.392781 | controller | skipping: Conditional result was False
2025-12-17 00:16:24.418257 | 
2025-12-17 00:16:24.418440 | TASK [include_role : remove-zuul-sshkey]
2025-12-17 00:16:24.445333 | controller | skipping: Conditional result was False
2025-12-17 00:16:24.461552 | 
2025-12-17 00:16:24.461777 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-17 00:16:24.700922 | controller | ok: "logs"
2025-12-17 00:16:24.701484 | controller | ok: All items complete
2025-12-17 00:16:24.701573 | 
2025-12-17 00:16:24.901498 | controller | ok: "artifacts"
2025-12-17 00:16:25.080094 | controller | ok: "docs"
2025-12-17 00:16:25.099029 | 
2025-12-17 00:16:25.099421 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-17 00:16:25.350470 | controller | changed: "logs"
2025-12-17 00:16:25.550475 | controller | changed: "artifacts"
2025-12-17 00:16:25.741222 | controller | changed: "docs"
2025-12-17 00:16:25.806206 | 
2025-12-17 00:16:25.806349 | PLAY RECAP
2025-12-17 00:16:25.806410 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-17 00:16:25.806448 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-17 00:16:25.806474 | 
2025-12-17 00:16:25.944895 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-17 00:16:25.945845 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-17 00:16:26.592403 | 
2025-12-17 00:16:26.592536 | PLAY [all]
2025-12-17 00:16:26.618504 | 
2025-12-17 00:16:26.618641 | TASK [Install binary dependencies]
2025-12-17 00:16:26.692310 | controller | ok
2025-12-17 00:16:26.725124 | 
2025-12-17 00:16:26.725277 | TASK [bindep : Include find tasks]
2025-12-17 00:16:26.757217 | controller | ok
2025-12-17 00:16:26.778813 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-17 00:16:26.786901 | 
2025-12-17 00:16:26.786988 | TASK [bindep : Look for bindep.txt]
2025-12-17 00:16:27.133627 | controller | ok
2025-12-17 00:16:27.143997 | 
2025-12-17 00:16:27.144206 | TASK [bindep : Define bindep_file fact]
2025-12-17 00:16:27.161350 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.176638 | 
2025-12-17 00:16:27.176883 | TASK [bindep : Look for other-requirements.txt]
2025-12-17 00:16:27.390946 | controller | ok
2025-12-17 00:16:27.409506 | 
2025-12-17 00:16:27.409846 | TASK [bindep : Define bindep_file fact]
2025-12-17 00:16:27.437451 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.451651 | 
2025-12-17 00:16:27.451810 | TASK [bindep : Look for bindep fallback file]
2025-12-17 00:16:27.477340 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.487455 | 
2025-12-17 00:16:27.487561 | TASK [bindep : Define bindep_file fact]
2025-12-17 00:16:27.512409 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.521064 | 
2025-12-17 00:16:27.521153 | TASK [bindep : Include bindep tasks]
2025-12-17 00:16:27.546286 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.555005 | 
2025-12-17 00:16:27.555098 | TASK [bindep : Include install tasks]
2025-12-17 00:16:27.579914 | controller | skipping: Conditional result was False
2025-12-17 00:16:27.588492 | 
2025-12-17 00:16:27.588591 | LOOP [bindep : Include package tasks]
2025-12-17 00:16:27.660366 | 
2025-12-17 00:16:27.660717 | TASK [Run test-setup role]
2025-12-17 00:16:27.686436 | controller | ok
2025-12-17 00:16:27.712101 | 
2025-12-17 00:16:27.712216 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-17 00:16:27.922855 | controller | ok
2025-12-17 00:16:27.936052 | 
2025-12-17 00:16:27.936188 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-17 00:16:28.493302 | controller | skipping: Conditional result was False
2025-12-17 00:16:28.550142 | 
2025-12-17 00:16:28.550354 | PLAY RECAP
2025-12-17 00:16:28.550418 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-17 00:16:28.550447 | 
2025-12-17 00:16:28.685648 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-17 00:16:28.686600 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-17 00:16:29.272562 | 
2025-12-17 00:16:29.272723 | PLAY [controller]
2025-12-17 00:16:29.292320 | 
2025-12-17 00:16:29.292407 | TASK [Create the /root directory]
2025-12-17 00:16:29.650907 | controller | ok
2025-12-17 00:16:29.658752 | 
2025-12-17 00:16:29.658854 | TASK [Install glibc-langpack-en]
2025-12-17 00:16:33.627775 | controller | ok: Nothing to do
2025-12-17 00:16:33.636370 | 
2025-12-17 00:16:33.636488 | TASK [Ensure controller directory exists]
2025-12-17 00:16:33.850113 | controller | changed
2025-12-17 00:16:33.863993 | 
2025-12-17 00:16:33.864137 | TASK [Install container runtime]
2025-12-17 00:16:33.932412 | controller | ok
2025-12-17 00:16:34.019756 | 
2025-12-17 00:16:34.019982 | LOOP [ensure-podman : Find distribution installation]
2025-12-17 00:16:34.048032 | controller | ok: "/var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-17 00:16:34.068164 | controller | included: /var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-17 00:16:34.078844 | 
2025-12-17 00:16:34.078955 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-17 00:17:37.958916 | controller | changed
2025-12-17 00:17:37.972277 | 
2025-12-17 00:17:37.972413 | TASK [ensure-podman : Fetch podman version]
2025-12-17 00:17:38.532847 | controller | Client:       Podman Engine
2025-12-17 00:17:38.568463 | controller | Version:      4.6.2
2025-12-17 00:17:38.568727 | controller | API Version:  4.6.2
2025-12-17 00:17:38.568746 | controller | Go Version:   go1.19.12
2025-12-17 00:17:38.568771 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-17 00:17:38.568783 | controller | OS/Arch:      linux/amd64
2025-12-17 00:17:39.019978 | controller | ok: Runtime: 0:00:00.197523
2025-12-17 00:17:39.027573 | 
2025-12-17 00:17:39.027660 | TASK [ensure-podman : Print podman version installed]
2025-12-17 00:17:39.050592 | Podman version: Client:       Podman Engine
2025-12-17 00:17:39.050787 | Version:      4.6.2
2025-12-17 00:17:39.050826 | API Version:  4.6.2
2025-12-17 00:17:39.050852 | Go Version:   go1.19.12
2025-12-17 00:17:39.050878 | Built:        Mon Aug 28 19:38:31 2023
2025-12-17 00:17:39.050904 | OS/Arch:      linux/amd64
2025-12-17 00:17:39.068034 | 
2025-12-17 00:17:39.068158 | TASK [ensure-podman : Validate podman engine]
2025-12-17 00:17:39.604958 | controller | skipping: Conditional result was False
2025-12-17 00:17:39.616823 | 
2025-12-17 00:17:39.616988 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-17 00:17:39.632592 | controller | skipping: Conditional result was False
2025-12-17 00:17:39.646730 | 
2025-12-17 00:17:39.646865 | TASK [Ensure python3.8 is present]
2025-12-17 00:17:39.662054 | controller | skipping: Conditional result was False
2025-12-17 00:17:39.674720 | 
2025-12-17 00:17:39.674822 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-17 00:17:39.697006 | controller | ok
2025-12-17 00:17:39.718828 | 
2025-12-17 00:17:39.718913 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-17 00:17:41.325381 | controller | ok: Nothing to do
2025-12-17 00:17:41.333640 | 
2025-12-17 00:17:41.333764 | TASK [our-ensure-python : Also install python3-devel]
2025-12-17 00:17:49.893040 | controller | changed
2025-12-17 00:17:49.919921 | 
2025-12-17 00:17:49.920033 | TASK [Run ensure-virtualenv role]
2025-12-17 00:17:49.945472 | controller | ok
2025-12-17 00:17:50.006355 | 
2025-12-17 00:17:50.006496 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-17 00:17:50.247809 | controller | /usr/bin/virtualenv
2025-12-17 00:17:50.552816 | controller | ok: Runtime: 0:00:00.005041
2025-12-17 00:17:50.566158 | 
2025-12-17 00:17:50.566312 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-17 00:17:50.605344 | controller | skipping: Conditional result was False
2025-12-17 00:17:50.605644 | controller | ok: All items complete
2025-12-17 00:17:50.605674 | 
2025-12-17 00:17:50.642095 | 
2025-12-17 00:17:50.642524 | TASK [Find the full path of the Python interpreter]
2025-12-17 00:17:50.925344 | controller | /usr/bin/python3
2025-12-17 00:17:51.215485 | controller | ok
2025-12-17 00:17:51.233749 | 
2025-12-17 00:17:51.233991 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-17 00:17:52.146444 | controller | created virtual environment CPython3.11.0.final.0-64 in 481ms
2025-12-17 00:17:52.165723 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-17 00:17:52.165770 | 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-17 00:17:52.165780 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-17 00:17:52.165795 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-17 00:17:52.292026 | controller | changed
2025-12-17 00:17:52.298964 | 
2025-12-17 00:17:52.299054 | TASK [Set selinux package]
2025-12-17 00:17:52.331800 | controller | ok
2025-12-17 00:17:52.344281 | 
2025-12-17 00:17:52.344423 | TASK [Set selinux package (Fedora)]
2025-12-17 00:17:52.393413 | controller | ok
2025-12-17 00:17:52.404894 | 
2025-12-17 00:17:52.405031 | TASK [Install selinux into virtualenv]
2025-12-17 00:18:29.833175 | controller | Collecting selinux-please-lie-to-me
2025-12-17 00:18:42.094672 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-17 00:18:42.397923 | controller | Collecting setuptools<50.0.0
2025-12-17 00:18:42.404195 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-17 00:18:42.439456 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.6 MB/s eta 0:00:00
2025-12-17 00:18:42.520413 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-17 00:18:42.520643 | controller |   Attempting uninstall: setuptools
2025-12-17 00:18:42.523114 | controller |     Found existing installation: setuptools 62.6.0
2025-12-17 00:18:42.583046 | controller |     Uninstalling setuptools-62.6.0:
2025-12-17 00:18:42.591367 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-17 00:18:42.937045 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-17 00:18:58.391154 | controller |
2025-12-17 00:18:58.468654 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-17 00:18:58.468694 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-17 00:18:58.511541 | controller | ok: Runtime: 0:01:05.855206
2025-12-17 00:18:58.524954 | 
2025-12-17 00:18:58.525205 | TASK [Install pytest-forked into virtualenv]
2025-12-17 00:19:10.613743 | controller | Collecting pytest-forked
2025-12-17 00:19:22.923320 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-17 00:19:22.963380 | controller | Collecting py
2025-12-17 00:19:22.968416 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-17 00:19:22.985930 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 7.3 MB/s eta 0:00:00
2025-12-17 00:19:23.088877 | controller | Collecting pytest>=3.10
2025-12-17 00:19:23.092954 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-17 00:19:23.107358 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.1 MB/s eta 0:00:00
2025-12-17 00:19:23.146224 | controller | Collecting iniconfig>=1.0.1
2025-12-17 00:19:23.150004 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-17 00:19:23.190365 | controller | Collecting packaging>=22
2025-12-17 00:19:23.193837 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-17 00:19:23.198938 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 19.2 MB/s eta 0:00:00
2025-12-17 00:19:23.229645 | controller | Collecting pluggy<2,>=1.5
2025-12-17 00:19:23.232684 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-17 00:19:23.278476 | controller | Collecting pygments>=2.7.2
2025-12-17 00:19:23.281592 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-17 00:19:23.305494 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 61.4 MB/s eta 0:00:00
2025-12-17 00:19:23.372912 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-17 00:19:24.391938 | 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-17 00:19:24.401198 | controller |
2025-12-17 00:19:24.468165 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-17 00:19:24.468196 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-17 00:19:24.593459 | controller | ok: Runtime: 0:00:25.708460
2025-12-17 00:19:24.614823 | 
2025-12-17 00:19:24.615121 | TASK [Update pip]
2025-12-17 00:19:25.150945 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-17 00:19:35.305891 | controller | Collecting pip
2025-12-17 00:19:47.500060 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-17 00:19:47.549574 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 38.9 MB/s eta 0:00:00
2025-12-17 00:19:47.613183 | controller | Installing collected packages: pip
2025-12-17 00:19:47.613375 | controller |   Attempting uninstall: pip
2025-12-17 00:19:47.615608 | controller |     Found existing installation: pip 22.2.2
2025-12-17 00:19:47.753324 | controller |     Uninstalling pip-22.2.2:
2025-12-17 00:19:47.768607 | controller |       Successfully uninstalled pip-22.2.2
2025-12-17 00:19:48.576335 | controller | Successfully installed pip-25.3
2025-12-17 00:19:48.693636 | controller | ok: Runtime: 0:00:23.788574
2025-12-17 00:19:48.703948 | 
2025-12-17 00:19:48.704086 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-17 00:19:48.932182 | controller | changed
2025-12-17 00:19:48.947817 | 
2025-12-17 00:19:48.948042 | TASK [Install ansible into virtualenv]
2025-12-17 00:19:49.451122 | controller | Processing ./src/github.com/ansible/ansible
2025-12-17 00:19:49.454521 | controller |   Installing build dependencies: started
2025-12-17 00:20:12.422093 | controller |   Installing build dependencies: finished with status 'done'
2025-12-17 00:20:12.423309 | controller |   Getting requirements to build wheel: started
2025-12-17 00:20:13.169279 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-17 00:20:13.170150 | controller |   Preparing metadata (pyproject.toml): started
2025-12-17 00:20:13.644551 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-17 00:20:13.651886 | 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-17 00:20:13.655877 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-17 00:20:14.014071 | controller | ERROR
2025-12-17 00:20:14.014599 | controller | {
2025-12-17 00:20:14.014718 | controller |   "delta": "0:00:24.552069",
2025-12-17 00:20:14.014773 | controller |   "end": "2025-12-17 00:20:13.717705",
2025-12-17 00:20:14.014811 | controller |   "msg": "non-zero return code",
2025-12-17 00:20:14.014864 | controller |   "rc": 1,
2025-12-17 00:20:14.014900 | controller |   "start": "2025-12-17 00:19:49.165636"
2025-12-17 00:20:14.014933 | controller | }
failure
2025-12-17 00:20:14.017471 | 
2025-12-17 00:20:14.017572 | PLAY RECAP
2025-12-17 00:20:14.017655 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-17 00:20:14.017749 | 
2025-12-17 00:20:14.202761 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-17 00:20:14.204721 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-17 00:20:14.846216 | 
2025-12-17 00:20:14.846335 | PLAY [all]
2025-12-17 00:20:14.869450 | 
2025-12-17 00:20:14.869574 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-17 00:20:15.113821 | controller | changed: non-zero return code
2025-12-17 00:20:15.120111 | 
2025-12-17 00:20:15.120187 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-17 00:20:15.148775 | controller | skipping: Conditional result was False
2025-12-17 00:20:15.156149 | 
2025-12-17 00:20:15.156224 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-17 00:20:15.188533 | 
2025-12-17 00:20:15.188724 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-17 00:20:15.219949 | 
2025-12-17 00:20:15.220098 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-17 00:20:15.244853 | controller | skipping: Conditional result was False
2025-12-17 00:20:15.255608 | 
2025-12-17 00:20:15.255747 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-17 00:20:15.290816 | 
2025-12-17 00:20:15.290995 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-17 00:20:15.316851 | controller | skipping: Conditional result was False
2025-12-17 00:20:15.325980 | 
2025-12-17 00:20:15.326104 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-17 00:20:15.352709 | controller | skipping: Conditional result was False
2025-12-17 00:20:15.361503 | 
2025-12-17 00:20:15.361642 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-17 00:20:15.386657 | controller | skipping: Conditional result was False
2025-12-17 00:20:15.424287 | 
2025-12-17 00:20:15.424402 | PLAY RECAP
2025-12-17 00:20:15.424456 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-17 00:20:15.424481 | 
2025-12-17 00:20:15.562894 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-17 00:20:15.564041 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-17 00:20:16.189018 | 
2025-12-17 00:20:16.189178 | PLAY [all:!appliance*]
2025-12-17 00:20:16.213854 | 
2025-12-17 00:20:16.214005 | TASK [unregister the node]
2025-12-17 00:20:16.748290 | controller | skipping: Conditional result was False
2025-12-17 00:20:16.761201 | 
2025-12-17 00:20:16.761387 | TASK [include_role : fetch-output]
2025-12-17 00:20:16.800410 | controller | ok
2025-12-17 00:20:16.842946 | 
2025-12-17 00:20:16.843043 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-17 00:20:16.909232 | controller | skipping: Conditional result was False
2025-12-17 00:20:16.918028 | 
2025-12-17 00:20:16.918122 | TASK [fetch-output : Set log path for single node]
2025-12-17 00:20:16.966150 | controller | ok
2025-12-17 00:20:16.978432 | 
2025-12-17 00:20:16.978575 | LOOP [fetch-output : Ensure local output dirs]
2025-12-17 00:20:17.431006 | controller -> localhost | ok: "/var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/logs"
2025-12-17 00:20:17.695301 | controller -> localhost | changed: "/var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/artifacts"
2025-12-17 00:20:17.938206 | controller -> localhost | changed: "/var/lib/zuul/builds/bc7baa5104f74b52b7232946b2e149d4/work/docs"
2025-12-17 00:20:17.952533 | 
2025-12-17 00:20:17.952718 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-17 00:20:18.666303 | controller | changed:
2025-12-17 00:20:18.666787 | controller | .d..t...... ./
2025-12-17 00:20:18.666879 | controller | cd+++++++++ controller/
2025-12-17 00:20:18.666976 | controller | changed: All items complete
2025-12-17 00:20:18.667042 | 
2025-12-17 00:20:19.147766 | controller | changed: .d..t...... ./
2025-12-17 00:20:19.651321 | controller | changed: .d..t...... ./
2025-12-17 00:20:19.673924 | 
2025-12-17 00:20:19.674191 | TASK [include_role : fetch-output-openshift]
2025-12-17 00:20:19.702233 | controller | skipping: Conditional result was False
2025-12-17 00:20:19.714312 | 
2025-12-17 00:20:19.714466 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-17 00:20:19.751813 | controller | skipping: Conditional result was False
2025-12-17 00:20:19.768304 | controller | skipping: Conditional result was False
2025-12-17 00:20:19.805931 | 
2025-12-17 00:20:19.806050 | PLAY [localhost]
2025-12-17 00:20:19.822191 | 
2025-12-17 00:20:19.822307 | TASK [Run Zuul manifest role]
2025-12-17 00:20:19.841283 | localhost | ok
2025-12-17 00:20:19.857897 | 
2025-12-17 00:20:19.858006 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-17 00:20:20.317115 | localhost | changed
2025-12-17 00:20:20.324036 | 
2025-12-17 00:20:20.324146 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-17 00:20:20.353835 | localhost | ok
2025-12-17 00:20:20.362502 | 
2025-12-17 00:20:20.362641 | TASK [Set zuul-log-path fact]
2025-12-17 00:20:20.384154 | localhost | ok
2025-12-17 00:20:20.408164 | 
2025-12-17 00:20:20.408349 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-17 00:20:20.444346 | localhost | ok
2025-12-17 00:20:20.456149 | 
2025-12-17 00:20:20.456251 | LOOP [Run upload-logs-swift role]
2025-12-17 00:20:20.495117 | localhost | Output suppressed because no_log was given
2025-12-17 00:20:20.550636 | 
2025-12-17 00:20:20.550823 | TASK [Set zuul-log-path fact]
2025-12-17 00:20:20.577568 | localhost | skipping: Conditional result was False
2025-12-17 00:20:20.587080 | 
2025-12-17 00:20:20.587227 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-17 00:20:21.025010 | localhost -> localhost | ok: Runtime: 0:00:00.008997
2025-12-17 00:20:21.071004 | 
2025-12-17 00:20:21.071162 | TASK [upload-logs-swift : Upload logs to swift]