2026-02-15 00:26:47.881152 | Job console starting...
2026-02-15 00:26:47.895146 | Updating repositories
2026-02-15 00:26:48.033361 | Preparing job workspace
2026-02-15 00:26:51.727696 | Running Ansible setup...
2026-02-15 00:27:00.009840 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:27:00.639759 | 
2026-02-15 00:27:00.639880 | PLAY [localhost]
2026-02-15 00:27:00.648331 | 
2026-02-15 00:27:00.648402 | TASK [Gathering Facts]
2026-02-15 00:27:01.626034 | localhost | ok
2026-02-15 00:27:01.649108 | 
2026-02-15 00:27:01.649268 | TASK [Setup log path fact]
2026-02-15 00:27:01.670720 | localhost | ok
2026-02-15 00:27:01.690474 | 
2026-02-15 00:27:01.690616 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:27:01.719713 | localhost | ok
2026-02-15 00:27:01.727619 | 
2026-02-15 00:27:01.727707 | TASK [emit-job-header : Print job information]
2026-02-15 00:27:01.765663 | # Job Information
2026-02-15 00:27:01.765833 | Ansible Version: 2.15.12
2026-02-15 00:27:01.765865 | Job: ansible-test-sanity-docker-devel
2026-02-15 00:27:01.765885 | Pipeline: periodic
2026-02-15 00:27:01.765903 | Executor: ze03.softwarefactory-project.io
2026-02-15 00:27:01.765921 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-15 00:27:01.765941 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/86b/ansible/86b5a162f29b46f594c9590dadecd8e8/
2026-02-15 00:27:01.765959 | Event ID: bfcfc7f67e194cfab2f082a1d8ce3d78
2026-02-15 00:27:01.770299 | 
2026-02-15 00:27:01.770392 | LOOP [emit-job-header : Print node information]
2026-02-15 00:27:01.877214 | localhost | ok:
2026-02-15 00:27:01.877573 | localhost | # Node Information
2026-02-15 00:27:01.877611 | localhost | Inventory Hostname: controller
2026-02-15 00:27:01.877632 | localhost | Hostname: np0005620038
2026-02-15 00:27:01.877650 | localhost | Username: zuul
2026-02-15 00:27:01.877674 | localhost | Distro: Fedora 37
2026-02-15 00:27:01.877692 | localhost | Provider: ansible-vexxhost-ams1
2026-02-15 00:27:01.877710 | localhost | Region: ams1
2026-02-15 00:27:01.877776 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-15 00:27:01.877806 | localhost | Product Name: OpenStack Nova
2026-02-15 00:27:01.877824 | localhost | Interface IP: 38.129.16.184
2026-02-15 00:27:01.896083 | 
2026-02-15 00:27:01.896219 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-15 00:27:02.277311 | localhost -> localhost | changed
2026-02-15 00:27:02.282991 | 
2026-02-15 00:27:02.283060 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-15 00:27:03.263959 | localhost -> localhost | changed
2026-02-15 00:27:03.293806 | 
2026-02-15 00:27:03.293917 | PLAY [all:!appliance*]
2026-02-15 00:27:03.316604 | 
2026-02-15 00:27:03.316689 | TASK [include_role : start-zuul-console]
2026-02-15 00:27:03.337289 | controller | ok
2026-02-15 00:27:03.352816 | 
2026-02-15 00:27:03.352929 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-15 00:27:04.461874 | controller | ok
2026-02-15 00:27:04.477324 | 
2026-02-15 00:27:04.477458 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-15 00:27:06.840718 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-15 00:27:06.849520 | 
2026-02-15 00:27:06.849608 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-15 00:27:07.218126 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.228110 | 
2026-02-15 00:27:07.228238 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-15 00:27:07.253842 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.264818 | 
2026-02-15 00:27:07.264965 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-15 00:27:07.290138 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.299847 | 
2026-02-15 00:27:07.299959 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-15 00:27:07.315615 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.325870 | 
2026-02-15 00:27:07.326040 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-15 00:27:07.341046 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.350696 | 
2026-02-15 00:27:07.350885 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-15 00:27:07.366332 | controller | skipping: Conditional result was False
2026-02-15 00:27:07.383830 | 
2026-02-15 00:27:07.383995 | TASK [Disable Fedora Modular]
2026-02-15 00:27:08.551186 | controller | changed
2026-02-15 00:27:08.558861 | 
2026-02-15 00:27:08.558959 | TASK [Enable EPEL]
2026-02-15 00:27:08.583841 | controller | skipping: Conditional result was False
2026-02-15 00:27:08.599930 | 
2026-02-15 00:27:08.600133 | TASK [Register the RHEL node]
2026-02-15 00:27:09.005418 | 
2026-02-15 00:27:09.005595 | TASK [Show the subscription-manager status]
2026-02-15 00:27:09.383372 | controller | skipping: Conditional result was False
2026-02-15 00:27:09.397895 | 
2026-02-15 00:27:09.398056 | TASK [Enable EPEL on RHEL]
2026-02-15 00:27:09.787518 | controller | skipping: Conditional result was False
2026-02-15 00:27:09.799872 | 
2026-02-15 00:27:09.800030 | TASK [Install git and tox]
2026-02-15 00:29:16.540166 | controller | changed
2026-02-15 00:29:16.552872 | 
2026-02-15 00:29:16.552964 | TASK [include_role : prepare-workspace]
2026-02-15 00:29:16.587938 | controller | ok
2026-02-15 00:29:16.638715 | 
2026-02-15 00:29:16.638948 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-15 00:29:17.467202 | controller | ok
2026-02-15 00:29:17.473981 | 
2026-02-15 00:29:17.474046 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-15 00:29:33.639958 | controller | Output suppressed because no_log was given
2026-02-15 00:29:33.649891 | 
2026-02-15 00:29:33.649997 | TASK [include_role : prepare-workspace-openshift]
2026-02-15 00:29:33.674649 | controller | skipping: Conditional result was False
2026-02-15 00:29:33.697142 | 
2026-02-15 00:29:33.697252 | PLAY [all:!appliance]
2026-02-15 00:29:33.713354 | 
2026-02-15 00:29:33.713489 | TASK [Run add-build-sshkey role (RSA)]
2026-02-15 00:29:33.754611 | controller | ok
2026-02-15 00:29:33.771471 | 
2026-02-15 00:29:33.771616 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:29:34.021342 | controller -> localhost | ok
2026-02-15 00:29:34.035213 | 
2026-02-15 00:29:34.035372 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:29:34.067289 | controller | ok
2026-02-15 00:29:34.099204 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:29:34.109568 | 
2026-02-15 00:29:34.109682 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:29:34.720379 | controller -> localhost | Generating public/private rsa key pair.
2026-02-15 00:29:34.720928 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_rsa.
2026-02-15 00:29:34.721011 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_rsa.pub.
2026-02-15 00:29:34.721067 | controller -> localhost | The key fingerprint is:
2026-02-15 00:29:34.721119 | controller -> localhost | SHA256:ptqD0vIxwKgFb+gWkmPqQRhFzizLWJT4V6SZn/QWK3E zuul-build-sshkey
2026-02-15 00:29:34.721169 | controller -> localhost | The key's randomart image is:
2026-02-15 00:29:34.721218 | controller -> localhost | +---[RSA 2048]----+
2026-02-15 00:29:34.721267 | controller -> localhost | | o+. ..          |
2026-02-15 00:29:34.721317 | controller -> localhost | |.*.  +.          |
2026-02-15 00:29:34.721365 | controller -> localhost | |+.= +.o E        |
2026-02-15 00:29:34.721413 | controller -> localhost | |+%. .o = o       |
2026-02-15 00:29:34.721459 | controller -> localhost | |X=*.  + S        |
2026-02-15 00:29:34.721522 | controller -> localhost | |B+..   =         |
2026-02-15 00:29:34.721584 | controller -> localhost | |o+ .o..          |
2026-02-15 00:29:34.721636 | controller -> localhost | |o + o=.          |
2026-02-15 00:29:34.721722 | controller -> localhost | | . +o ..         |
2026-02-15 00:29:34.721823 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:29:34.721956 | controller -> localhost | ok: Runtime: 0:00:00.136903
2026-02-15 00:29:34.738392 | 
2026-02-15 00:29:34.738508 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:29:34.777369 | controller | ok
2026-02-15 00:29:34.793343 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:29:34.806554 | 
2026-02-15 00:29:34.806646 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:29:34.832689 | controller | skipping: Conditional result was False
2026-02-15 00:29:34.842950 | 
2026-02-15 00:29:34.843044 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:29:35.934122 | controller | changed
2026-02-15 00:29:35.942571 | 
2026-02-15 00:29:35.942666 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:29:36.645930 | controller | ok
2026-02-15 00:29:36.660872 | 
2026-02-15 00:29:36.661038 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:29:39.709443 | controller | changed
2026-02-15 00:29:39.718935 | 
2026-02-15 00:29:39.719064 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:29:46.187438 | controller | changed
2026-02-15 00:29:46.193333 | 
2026-02-15 00:29:46.193398 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:29:46.217808 | controller | skipping: Conditional result was False
2026-02-15 00:29:46.224371 | 
2026-02-15 00:29:46.224441 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:29:47.458319 | controller -> localhost | changed
2026-02-15 00:29:47.469826 | 
2026-02-15 00:29:47.469902 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:29:47.986588 | controller -> localhost | Identity added: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_rsa (zuul-build-sshkey)
2026-02-15 00:29:47.986866 | controller -> localhost | ok: Runtime: 0:00:00.008496
2026-02-15 00:29:47.993234 | 
2026-02-15 00:29:47.993298 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:29:48.827836 | controller | ok
2026-02-15 00:29:48.837317 | 
2026-02-15 00:29:48.837419 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:29:48.887184 | controller | skipping: Conditional result was False
2026-02-15 00:29:48.899058 | 
2026-02-15 00:29:48.899185 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-15 00:29:48.920187 | controller | ok
2026-02-15 00:29:48.942915 | 
2026-02-15 00:29:48.943032 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:29:49.173061 | controller -> localhost | ok
2026-02-15 00:29:49.179847 | 
2026-02-15 00:29:49.179918 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:29:49.211797 | controller | ok
2026-02-15 00:29:49.225284 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:29:49.233834 | 
2026-02-15 00:29:49.233969 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:29:49.612611 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-15 00:29:49.612776 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_ecdsa.
2026-02-15 00:29:49.612804 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_ecdsa.pub.
2026-02-15 00:29:49.612835 | controller -> localhost | The key fingerprint is:
2026-02-15 00:29:49.612855 | controller -> localhost | SHA256:Ca/6BUC6hEPKIdIIXop6JgTF0RWGY3gc2SheT/S3Ytk zuul-build-sshkey
2026-02-15 00:29:49.612873 | controller -> localhost | The key's randomart image is:
2026-02-15 00:29:49.612892 | controller -> localhost | +---[ECDSA 521]---+
2026-02-15 00:29:49.612909 | controller -> localhost | |*Bo*oO=.         |
2026-02-15 00:29:49.612926 | controller -> localhost | |@.Oo@.o.         |
2026-02-15 00:29:49.612943 | controller -> localhost | |=*o=.+. . .      |
2026-02-15 00:29:49.612960 | controller -> localhost | |oo.. ..o = .     |
2026-02-15 00:29:49.612978 | controller -> localhost | |o +   . S E      |
2026-02-15 00:29:49.612995 | controller -> localhost | | +     + .       |
2026-02-15 00:29:49.613012 | controller -> localhost | |      . .        |
2026-02-15 00:29:49.613028 | controller -> localhost | |     . .         |
2026-02-15 00:29:49.613045 | controller -> localhost | |    ...          |
2026-02-15 00:29:49.613062 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:29:49.613098 | controller -> localhost | ok: Runtime: 0:00:00.012944
2026-02-15 00:29:49.619273 | 
2026-02-15 00:29:49.619339 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:29:49.652213 | controller | ok
2026-02-15 00:29:49.666250 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:29:49.691935 | 
2026-02-15 00:29:49.692037 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:29:49.716552 | controller | skipping: Conditional result was False
2026-02-15 00:29:49.724954 | 
2026-02-15 00:29:49.725044 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:29:50.532143 | controller | changed
2026-02-15 00:29:50.538836 | 
2026-02-15 00:29:50.538921 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:29:51.181335 | controller | ok
2026-02-15 00:29:51.199909 | 
2026-02-15 00:29:51.200021 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:29:54.502563 | controller | changed
2026-02-15 00:29:54.511272 | 
2026-02-15 00:29:54.511367 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:29:57.578003 | controller | changed
2026-02-15 00:29:57.586355 | 
2026-02-15 00:29:57.586460 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:29:57.622185 | controller | skipping: Conditional result was False
2026-02-15 00:29:57.631991 | 
2026-02-15 00:29:57.632102 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:29:57.951988 | controller -> localhost | changed
2026-02-15 00:29:57.963890 | 
2026-02-15 00:29:57.963982 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:29:58.296987 | controller -> localhost | Identity added: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/86b5a162f29b46f594c9590dadecd8e8_id_ecdsa (zuul-build-sshkey)
2026-02-15 00:29:58.297382 | controller -> localhost | ok: Runtime: 0:00:00.014906
2026-02-15 00:29:58.315962 | 
2026-02-15 00:29:58.316105 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:29:59.146578 | controller | ok
2026-02-15 00:29:59.159281 | 
2026-02-15 00:29:59.159443 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:29:59.188297 | controller | skipping: Conditional result was False
2026-02-15 00:29:59.217464 | 
2026-02-15 00:29:59.217690 | TASK [include_role : remove-zuul-sshkey]
2026-02-15 00:29:59.257782 | controller | skipping: Conditional result was False
2026-02-15 00:29:59.277191 | 
2026-02-15 00:29:59.277451 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-15 00:30:00.014118 | controller | ok: "logs"
2026-02-15 00:30:00.014494 | controller | ok: All items complete
2026-02-15 00:30:00.014558 | 
2026-02-15 00:30:00.734626 | controller | ok: "artifacts"
2026-02-15 00:30:01.399655 | controller | ok: "docs"
2026-02-15 00:30:01.430926 | 
2026-02-15 00:30:01.431129 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-15 00:30:02.190105 | controller | changed: "logs"
2026-02-15 00:30:02.855066 | controller | changed: "artifacts"
2026-02-15 00:30:03.469484 | controller | changed: "docs"
2026-02-15 00:30:03.514830 | 
2026-02-15 00:30:03.514955 | PLAY RECAP
2026-02-15 00:30:03.515017 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-15 00:30:03.515056 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-15 00:30:03.515085 | 
2026-02-15 00:30:03.663278 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:30:03.664172 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:30:04.318964 | 
2026-02-15 00:30:04.319089 | PLAY [all]
2026-02-15 00:30:04.341659 | 
2026-02-15 00:30:04.341829 | TASK [Install binary dependencies]
2026-02-15 00:30:04.425568 | controller | ok
2026-02-15 00:30:04.456272 | 
2026-02-15 00:30:04.456502 | TASK [bindep : Include find tasks]
2026-02-15 00:30:04.506224 | controller | ok
2026-02-15 00:30:04.520373 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-15 00:30:04.529995 | 
2026-02-15 00:30:04.530110 | TASK [bindep : Look for bindep.txt]
2026-02-15 00:30:05.485830 | controller | ok
2026-02-15 00:30:05.495061 | 
2026-02-15 00:30:05.495198 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:30:05.510890 | controller | skipping: Conditional result was False
2026-02-15 00:30:05.521273 | 
2026-02-15 00:30:05.521437 | TASK [bindep : Look for other-requirements.txt]
2026-02-15 00:30:06.380929 | controller | ok
2026-02-15 00:30:06.388047 | 
2026-02-15 00:30:06.388132 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:30:06.424193 | controller | skipping: Conditional result was False
2026-02-15 00:30:06.440957 | 
2026-02-15 00:30:06.441177 | TASK [bindep : Look for bindep fallback file]
2026-02-15 00:30:06.470337 | controller | skipping: Conditional result was False
2026-02-15 00:30:06.479286 | 
2026-02-15 00:30:06.479385 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:30:06.515806 | controller | skipping: Conditional result was False
2026-02-15 00:30:06.527766 | 
2026-02-15 00:30:06.527874 | TASK [bindep : Include bindep tasks]
2026-02-15 00:30:06.554042 | controller | skipping: Conditional result was False
2026-02-15 00:30:06.563295 | 
2026-02-15 00:30:06.563391 | TASK [bindep : Include install tasks]
2026-02-15 00:30:06.589554 | controller | skipping: Conditional result was False
2026-02-15 00:30:06.601680 | 
2026-02-15 00:30:06.601907 | LOOP [bindep : Include package tasks]
2026-02-15 00:30:06.663777 | 
2026-02-15 00:30:06.663994 | TASK [Run test-setup role]
2026-02-15 00:30:06.686846 | controller | ok
2026-02-15 00:30:06.706815 | 
2026-02-15 00:30:06.706908 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-15 00:30:07.974390 | controller | ok
2026-02-15 00:30:07.987337 | 
2026-02-15 00:30:07.987477 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-15 00:30:09.388987 | controller | skipping: Conditional result was False
2026-02-15 00:30:09.416487 | 
2026-02-15 00:30:09.416625 | PLAY RECAP
2026-02-15 00:30:09.416671 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:30:09.416713 | 
2026-02-15 00:30:09.536174 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:30:09.537072 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:30:10.163380 | 
2026-02-15 00:30:10.163512 | PLAY [controller]
2026-02-15 00:30:10.185028 | 
2026-02-15 00:30:10.185168 | TASK [Create the /root directory]
2026-02-15 00:30:11.137634 | controller | ok
2026-02-15 00:30:11.148728 | 
2026-02-15 00:30:11.148897 | TASK [Install glibc-langpack-en]
2026-02-15 00:30:18.799507 | controller | ok: Nothing to do
2026-02-15 00:30:18.808971 | 
2026-02-15 00:30:18.809100 | TASK [Ensure controller directory exists]
2026-02-15 00:30:19.718536 | controller | changed
2026-02-15 00:30:19.726689 | 
2026-02-15 00:30:19.726813 | TASK [Install container runtime]
2026-02-15 00:30:19.808349 | controller | ok
2026-02-15 00:30:19.866579 | 
2026-02-15 00:30:19.866765 | LOOP [ensure-podman : Find distribution installation]
2026-02-15 00:30:19.914278 | controller | ok: "/var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-15 00:30:19.922183 | controller | included: /var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-15 00:30:19.928904 | 
2026-02-15 00:30:19.929012 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-15 00:32:17.440657 | controller | changed
2026-02-15 00:32:17.451109 | 
2026-02-15 00:32:17.451215 | TASK [ensure-podman : Fetch podman version]
2026-02-15 00:32:18.648012 | controller | Client:       Podman Engine
2026-02-15 00:32:18.687289 | controller | Version:      4.6.2
2026-02-15 00:32:18.687386 | controller | API Version:  4.6.2
2026-02-15 00:32:18.687395 | controller | Go Version:   go1.19.12
2026-02-15 00:32:18.687422 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:32:18.687431 | controller | OS/Arch:      linux/amd64
2026-02-15 00:32:18.824247 | controller | ok: Runtime: 0:00:00.295964
2026-02-15 00:32:18.834216 | 
2026-02-15 00:32:18.834313 | TASK [ensure-podman : Print podman version installed]
2026-02-15 00:32:18.879270 | Podman version: Client:       Podman Engine
2026-02-15 00:32:18.879487 | Version:      4.6.2
2026-02-15 00:32:18.879526 | API Version:  4.6.2
2026-02-15 00:32:18.879554 | Go Version:   go1.19.12
2026-02-15 00:32:18.879581 | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:32:18.879607 | OS/Arch:      linux/amd64
2026-02-15 00:32:18.887864 | 
2026-02-15 00:32:18.887950 | TASK [ensure-podman : Validate podman engine]
2026-02-15 00:32:19.256072 | controller | skipping: Conditional result was False
2026-02-15 00:32:19.270293 | 
2026-02-15 00:32:19.270452 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-15 00:32:19.297947 | controller | skipping: Conditional result was False
2026-02-15 00:32:19.327983 | 
2026-02-15 00:32:19.328222 | TASK [Ensure python3.8 is present]
2026-02-15 00:32:19.357053 | controller | skipping: Conditional result was False
2026-02-15 00:32:19.368064 | 
2026-02-15 00:32:19.368206 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-15 00:32:19.402607 | controller | ok
2026-02-15 00:32:19.433956 | 
2026-02-15 00:32:19.434105 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-15 00:32:23.040488 | controller | ok: Nothing to do
2026-02-15 00:32:23.054170 | 
2026-02-15 00:32:23.054323 | TASK [our-ensure-python : Also install python3-devel]
2026-02-15 00:32:38.295430 | controller | changed
2026-02-15 00:32:38.321432 | 
2026-02-15 00:32:38.321673 | TASK [Run ensure-virtualenv role]
2026-02-15 00:32:38.362796 | controller | ok
2026-02-15 00:32:38.401659 | 
2026-02-15 00:32:38.401871 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-15 00:32:39.217862 | controller | /usr/bin/virtualenv
2026-02-15 00:32:39.812485 | controller | ok: Runtime: 0:00:00.007252
2026-02-15 00:32:39.822238 | 
2026-02-15 00:32:39.822417 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-15 00:32:39.859695 | controller | skipping: Conditional result was False
2026-02-15 00:32:39.860178 | controller | ok: All items complete
2026-02-15 00:32:39.860216 | 
2026-02-15 00:32:39.884550 | 
2026-02-15 00:32:39.884756 | TASK [Find the full path of the Python interpreter]
2026-02-15 00:32:40.718366 | controller | /usr/bin/python3
2026-02-15 00:32:41.245821 | controller | ok
2026-02-15 00:32:41.255507 | 
2026-02-15 00:32:41.255684 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-15 00:32:43.276620 | controller | created virtual environment CPython3.11.0.final.0-64 in 1022ms
2026-02-15 00:32:43.363965 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-15 00:32:43.364079 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2026-02-15 00:32:43.364098 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-15 00:32:43.364123 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-15 00:32:43.620050 | controller | changed
2026-02-15 00:32:43.635093 | 
2026-02-15 00:32:43.635235 | TASK [Set selinux package]
2026-02-15 00:32:43.675488 | controller | ok
2026-02-15 00:32:43.687187 | 
2026-02-15 00:32:43.687330 | TASK [Set selinux package (Fedora)]
2026-02-15 00:32:43.747589 | controller | ok
2026-02-15 00:32:43.759147 | 
2026-02-15 00:32:43.759282 | TASK [Install selinux into virtualenv]
2026-02-15 00:32:46.982198 | controller | Collecting selinux-please-lie-to-me
2026-02-15 00:32:47.062516 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-15 00:32:47.645268 | controller | Collecting setuptools<50.0.0
2026-02-15 00:32:47.652808 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-15 00:32:47.713507 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 14.5 MB/s eta 0:00:00
2026-02-15 00:32:47.856154 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-15 00:32:47.856477 | controller |   Attempting uninstall: setuptools
2026-02-15 00:32:47.861119 | controller |     Found existing installation: setuptools 62.6.0
2026-02-15 00:32:47.969750 | controller |     Uninstalling setuptools-62.6.0:
2026-02-15 00:32:47.983020 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-15 00:32:48.806689 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-15 00:32:49.024743 | controller |
2026-02-15 00:32:49.337405 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:32:49.337458 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:32:49.659835 | controller | ok: Runtime: 0:00:04.778362
2026-02-15 00:32:49.669983 | 
2026-02-15 00:32:49.670105 | TASK [Install pytest-forked into virtualenv]
2026-02-15 00:32:51.153694 | controller | Collecting pytest-forked
2026-02-15 00:32:51.222191 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-15 00:32:51.279475 | controller | Collecting py
2026-02-15 00:32:51.284854 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-15 00:32:51.319161 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00
2026-02-15 00:32:51.510531 | controller | Collecting pytest>=3.10
2026-02-15 00:32:51.517130 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-15 00:32:51.543412 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.0 MB/s eta 0:00:00
2026-02-15 00:32:51.612906 | controller | Collecting iniconfig>=1.0.1
2026-02-15 00:32:51.617874 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-15 00:32:51.685179 | controller | Collecting packaging>=22
2026-02-15 00:32:51.697772 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-15 00:32:51.711183 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 6.5 MB/s eta 0:00:00
2026-02-15 00:32:51.769577 | controller | Collecting pluggy<2,>=1.5
2026-02-15 00:32:51.775706 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-15 00:32:51.855400 | controller | Collecting pygments>=2.7.2
2026-02-15 00:32:51.862997 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-15 00:32:51.910336 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 28.8 MB/s eta 0:00:00
2026-02-15 00:32:52.030094 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-15 00:32:54.226562 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-02-15 00:32:54.240826 | controller |
2026-02-15 00:32:54.440325 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:32:54.440376 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:32:55.051321 | controller | ok: Runtime: 0:00:03.993044
2026-02-15 00:32:55.058990 | 
2026-02-15 00:32:55.059089 | TASK [Update pip]
2026-02-15 00:32:56.580858 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-15 00:32:56.907805 | controller | Collecting pip
2026-02-15 00:32:56.994784 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-15 00:32:57.092769 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 20.1 MB/s eta 0:00:00
2026-02-15 00:32:57.202402 | controller | Installing collected packages: pip
2026-02-15 00:32:57.202816 | controller |   Attempting uninstall: pip
2026-02-15 00:32:57.206460 | controller |     Found existing installation: pip 22.2.2
2026-02-15 00:32:57.436081 | controller |     Uninstalling pip-22.2.2:
2026-02-15 00:32:57.479569 | controller |       Successfully uninstalled pip-22.2.2
2026-02-15 00:32:59.353638 | controller | Successfully installed pip-26.0.1
2026-02-15 00:32:59.927709 | controller | ok: Runtime: 0:00:03.678194
2026-02-15 00:32:59.934039 | 
2026-02-15 00:32:59.934116 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-15 00:33:00.831717 | controller | changed
2026-02-15 00:33:00.845218 | 
2026-02-15 00:33:00.845372 | TASK [Install ansible into virtualenv]
2026-02-15 00:33:02.044730 | controller | Processing ./src/github.com/ansible/ansible
2026-02-15 00:33:02.048646 | controller |   Installing build dependencies: started
2026-02-15 00:33:03.618431 | controller |   Installing build dependencies: finished with status 'done'
2026-02-15 00:33:05.144268 | controller |   Getting requirements to build wheel: started
2026-02-15 00:33:05.144324 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-15 00:33:05.985118 | controller |   Preparing metadata (pyproject.toml): started
2026-02-15 00:33:05.985166 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-15 00:33:05.986523 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while.
2026-02-15 00:33:05.986547 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-15 00:33:06.259803 | controller | ERROR
2026-02-15 00:33:06.260096 | controller | {
2026-02-15 00:33:06.260136 | controller |   "delta": "0:00:04.607081",
2026-02-15 00:33:06.260163 | controller |   "end": "2026-02-15 00:33:06.129651",
2026-02-15 00:33:06.260186 | controller |   "msg": "non-zero return code",
2026-02-15 00:33:06.260225 | controller |   "rc": 1,
2026-02-15 00:33:06.260322 | controller |   "start": "2026-02-15 00:33:01.522570"
2026-02-15 00:33:06.260346 | controller | }
failure
2026-02-15 00:33:06.262662 | 
2026-02-15 00:33:06.262720 | PLAY RECAP
2026-02-15 00:33:06.262805 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-15 00:33:06.262836 | 
2026-02-15 00:33:06.416699 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:33:06.417795 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:33:07.024354 | 
2026-02-15 00:33:07.024480 | PLAY [all]
2026-02-15 00:33:07.046125 | 
2026-02-15 00:33:07.046288 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-15 00:33:08.895394 | controller | changed: non-zero return code
2026-02-15 00:33:08.908703 | 
2026-02-15 00:33:08.908924 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-15 00:33:08.935280 | controller | skipping: Conditional result was False
2026-02-15 00:33:08.943491 | 
2026-02-15 00:33:08.943586 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-15 00:33:08.987670 | 
2026-02-15 00:33:08.988015 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-15 00:33:09.024306 | 
2026-02-15 00:33:09.024517 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-15 00:33:09.043264 | controller | skipping: Conditional result was False
2026-02-15 00:33:09.056862 | 
2026-02-15 00:33:09.057076 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-15 00:33:09.090406 | 
2026-02-15 00:33:09.090617 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-15 00:33:09.115291 | controller | skipping: Conditional result was False
2026-02-15 00:33:09.121642 | 
2026-02-15 00:33:09.121720 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-15 00:33:09.146230 | controller | skipping: Conditional result was False
2026-02-15 00:33:09.153058 | 
2026-02-15 00:33:09.153409 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-15 00:33:09.177957 | controller | skipping: Conditional result was False
2026-02-15 00:33:09.205407 | 
2026-02-15 00:33:09.205504 | PLAY RECAP
2026-02-15 00:33:09.205547 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:33:09.205567 | 
2026-02-15 00:33:09.336971 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:33:09.338070 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-15 00:33:10.031249 | 
2026-02-15 00:33:10.031395 | PLAY [all:!appliance*]
2026-02-15 00:33:10.052966 | 
2026-02-15 00:33:10.053068 | TASK [unregister the node]
2026-02-15 00:33:10.404518 | controller | skipping: Conditional result was False
2026-02-15 00:33:10.417586 | 
2026-02-15 00:33:10.417788 | TASK [include_role : fetch-output]
2026-02-15 00:33:10.456503 | controller | ok
2026-02-15 00:33:10.492763 | 
2026-02-15 00:33:10.492890 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-15 00:33:10.539882 | controller | skipping: Conditional result was False
2026-02-15 00:33:10.553909 | 
2026-02-15 00:33:10.554073 | TASK [fetch-output : Set log path for single node]
2026-02-15 00:33:10.604209 | controller | ok
2026-02-15 00:33:10.616639 | 
2026-02-15 00:33:10.616810 | LOOP [fetch-output : Ensure local output dirs]
2026-02-15 00:33:11.113847 | controller -> localhost | ok: "/var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/logs"
2026-02-15 00:33:11.406825 | controller -> localhost | changed: "/var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/artifacts"
2026-02-15 00:33:11.674019 | controller -> localhost | changed: "/var/lib/zuul/builds/86b5a162f29b46f594c9590dadecd8e8/work/docs"
2026-02-15 00:33:11.683770 | 
2026-02-15 00:33:11.684025 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-15 00:33:13.947634 | controller | changed:
2026-02-15 00:33:13.948120 | controller | .d..t...... ./
2026-02-15 00:33:13.948186 | controller | cd+++++++++ controller/
2026-02-15 00:33:13.948255 | controller | changed: All items complete
2026-02-15 00:33:13.948298 | 
2026-02-15 00:33:16.016398 | controller | changed: .d..t...... ./
2026-02-15 00:33:18.112166 | controller | changed: .d..t...... ./
2026-02-15 00:33:18.128697 | 
2026-02-15 00:33:18.128887 | TASK [include_role : fetch-output-openshift]
2026-02-15 00:33:18.153934 | controller | skipping: Conditional result was False
2026-02-15 00:33:18.161716 | 
2026-02-15 00:33:18.161862 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-15 00:33:18.197342 | controller | skipping: Conditional result was False
2026-02-15 00:33:18.206429 | controller | skipping: Conditional result was False
2026-02-15 00:33:18.241113 | 
2026-02-15 00:33:18.241240 | PLAY [localhost]
2026-02-15 00:33:18.257233 | 
2026-02-15 00:33:18.257391 | TASK [Run Zuul manifest role]
2026-02-15 00:33:18.277558 | localhost | ok
2026-02-15 00:33:18.293177 | 
2026-02-15 00:33:18.293333 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-15 00:33:18.663055 | localhost | changed
2026-02-15 00:33:18.667615 | 
2026-02-15 00:33:18.667677 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-15 00:33:18.696327 | localhost | ok
2026-02-15 00:33:18.704499 | 
2026-02-15 00:33:18.704560 | TASK [Set zuul-log-path fact]
2026-02-15 00:33:18.723263 | localhost | ok
2026-02-15 00:33:18.771431 | 
2026-02-15 00:33:18.771569 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:33:18.811442 | localhost | ok
2026-02-15 00:33:18.819707 | 
2026-02-15 00:33:18.819830 | LOOP [Run upload-logs-swift role]
2026-02-15 00:33:18.854335 | localhost | Output suppressed because no_log was given
2026-02-15 00:33:18.879472 | 
2026-02-15 00:33:18.879600 | TASK [Set zuul-log-path fact]
2026-02-15 00:33:18.913938 | localhost | skipping: Conditional result was False
2026-02-15 00:33:18.920537 | 
2026-02-15 00:33:18.920641 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-15 00:33:19.312504 | localhost -> localhost | ok: Runtime: 0:00:00.008530
2026-02-15 00:33:19.318185 | 
2026-02-15 00:33:19.318276 | TASK [upload-logs-swift : Upload logs to swift]