2026-02-13 00:18:20.204790 | Job console starting...
2026-02-13 00:18:20.215245 | Updating repositories
2026-02-13 00:18:20.335687 | Preparing job workspace
2026-02-13 00:18:24.269714 | Running Ansible setup...
2026-02-13 00:18:32.454907 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:18:33.140390 | 
2026-02-13 00:18:33.140544 | PLAY [localhost]
2026-02-13 00:18:33.156210 | 
2026-02-13 00:18:33.156342 | TASK [Gathering Facts]
2026-02-13 00:18:34.224847 | localhost | ok
2026-02-13 00:18:34.241238 | 
2026-02-13 00:18:34.241417 | TASK [Setup log path fact]
2026-02-13 00:18:34.272408 | localhost | ok
2026-02-13 00:18:34.288431 | 
2026-02-13 00:18:34.288547 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:18:34.328019 | localhost | ok
2026-02-13 00:18:34.337874 | 
2026-02-13 00:18:34.338003 | TASK [emit-job-header : Print job information]
2026-02-13 00:18:34.368349 | # Job Information
2026-02-13 00:18:34.368548 | Ansible Version: 2.15.12
2026-02-13 00:18:34.368580 | Job: ansible-test-sanity-docker-devel
2026-02-13 00:18:34.368601 | Pipeline: periodic
2026-02-13 00:18:34.368620 | Executor: ze02.softwarefactory-project.io
2026-02-13 00:18:34.368645 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-13 00:18:34.368694 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b13/ansible/b13d6a8d90c54877ae27ab6df0d07c80/
2026-02-13 00:18:34.368716 | Event ID: 0fb89987ddbf4579b8946ad3b376b620
2026-02-13 00:18:34.372905 | 
2026-02-13 00:18:34.372978 | LOOP [emit-job-header : Print node information]
2026-02-13 00:18:34.478706 | localhost | ok:
2026-02-13 00:18:34.478925 | localhost | # Node Information
2026-02-13 00:18:34.478965 | localhost | Inventory Hostname: controller
2026-02-13 00:18:34.478994 | localhost | Hostname: np0005618406
2026-02-13 00:18:34.479022 | localhost | Username: zuul
2026-02-13 00:18:34.479053 | localhost | Distro: Fedora 37
2026-02-13 00:18:34.479083 | localhost | Provider: ansible-vexxhost-ams1
2026-02-13 00:18:34.479109 | localhost | Region: ams1
2026-02-13 00:18:34.479134 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-13 00:18:34.479158 | localhost | Product Name: OpenStack Nova
2026-02-13 00:18:34.479183 | localhost | Interface IP: 38.129.16.14
2026-02-13 00:18:34.488539 | 
2026-02-13 00:18:34.488689 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-13 00:18:34.921852 | localhost -> localhost | changed
2026-02-13 00:18:34.934517 | 
2026-02-13 00:18:34.934701 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-13 00:18:35.918698 | localhost -> localhost | changed
2026-02-13 00:18:35.949686 | 
2026-02-13 00:18:35.949815 | PLAY [all:!appliance*]
2026-02-13 00:18:35.969886 | 
2026-02-13 00:18:35.970094 | TASK [include_role : start-zuul-console]
2026-02-13 00:18:35.990854 | controller | ok
2026-02-13 00:18:36.005090 | 
2026-02-13 00:18:36.005176 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-13 00:18:37.049347 | controller | ok
2026-02-13 00:18:37.069409 | 
2026-02-13 00:18:37.069607 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-13 00:18:39.821705 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-13 00:18:39.831552 | 
2026-02-13 00:18:39.831683 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-13 00:18:40.198706 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.212402 | 
2026-02-13 00:18:40.212557 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-13 00:18:40.244623 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.260362 | 
2026-02-13 00:18:40.260529 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-13 00:18:40.289179 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.299297 | 
2026-02-13 00:18:40.299395 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-13 00:18:40.324354 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.340459 | 
2026-02-13 00:18:40.340591 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-13 00:18:40.367074 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.376657 | 
2026-02-13 00:18:40.376781 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-13 00:18:40.403219 | controller | skipping: Conditional result was False
2026-02-13 00:18:40.423606 | 
2026-02-13 00:18:40.423765 | TASK [Disable Fedora Modular]
2026-02-13 00:18:41.542598 | controller | changed
2026-02-13 00:18:41.555165 | 
2026-02-13 00:18:41.555307 | TASK [Enable EPEL]
2026-02-13 00:18:41.571984 | controller | skipping: Conditional result was False
2026-02-13 00:18:41.585743 | 
2026-02-13 00:18:41.585889 | TASK [Register the RHEL node]
2026-02-13 00:18:42.042101 | 
2026-02-13 00:18:42.043078 | TASK [Show the subscription-manager status]
2026-02-13 00:18:42.440053 | controller | skipping: Conditional result was False
2026-02-13 00:18:42.456360 | 
2026-02-13 00:18:42.456549 | TASK [Enable EPEL on RHEL]
2026-02-13 00:18:42.851193 | controller | skipping: Conditional result was False
2026-02-13 00:18:42.866897 | 
2026-02-13 00:18:42.867096 | TASK [Install git and tox]
2026-02-13 00:22:00.058757 | controller | changed
2026-02-13 00:22:00.065340 | 
2026-02-13 00:22:00.065411 | TASK [include_role : prepare-workspace]
2026-02-13 00:22:00.095091 | controller | ok
2026-02-13 00:22:00.116891 | 
2026-02-13 00:22:00.116991 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-13 00:22:00.979758 | controller | ok
2026-02-13 00:22:00.998106 | 
2026-02-13 00:22:00.998257 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-13 00:22:18.936613 | controller | Output suppressed because no_log was given
2026-02-13 00:22:18.952267 | 
2026-02-13 00:22:18.952362 | TASK [include_role : prepare-workspace-openshift]
2026-02-13 00:22:18.980437 | controller | skipping: Conditional result was False
2026-02-13 00:22:19.019273 | 
2026-02-13 00:22:19.019437 | PLAY [all:!appliance]
2026-02-13 00:22:19.057161 | 
2026-02-13 00:22:19.057278 | TASK [Run add-build-sshkey role (RSA)]
2026-02-13 00:22:19.089338 | controller | ok
2026-02-13 00:22:19.107107 | 
2026-02-13 00:22:19.107248 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:22:19.419180 | controller -> localhost | ok
2026-02-13 00:22:19.436288 | 
2026-02-13 00:22:19.436463 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:22:19.476035 | controller | ok
2026-02-13 00:22:19.501206 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:22:19.511006 | 
2026-02-13 00:22:19.511097 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:22:20.080631 | controller -> localhost | Generating public/private rsa key pair.
2026-02-13 00:22:20.080975 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_rsa.
2026-02-13 00:22:20.081016 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_rsa.pub.
2026-02-13 00:22:20.081045 | controller -> localhost | The key fingerprint is:
2026-02-13 00:22:20.081072 | controller -> localhost | SHA256:XX9eAoextLRbJdF2uAkwlpE002OhG6FNxnmbyN1bsbU zuul-build-sshkey
2026-02-13 00:22:20.081099 | controller -> localhost | The key's randomart image is:
2026-02-13 00:22:20.081124 | controller -> localhost | +---[RSA 2048]----+
2026-02-13 00:22:20.081150 | controller -> localhost | |         o%B=.o+.|
2026-02-13 00:22:20.081175 | controller -> localhost | |         *=O**.+=|
2026-02-13 00:22:20.081200 | controller -> localhost | |        ..+=B*o+*|
2026-02-13 00:22:20.081225 | controller -> localhost | |         .o++*+E.|
2026-02-13 00:22:20.081249 | controller -> localhost | |        S o . ooo|
2026-02-13 00:22:20.081291 | controller -> localhost | |              .+.|
2026-02-13 00:22:20.081323 | controller -> localhost | |                .|
2026-02-13 00:22:20.081351 | controller -> localhost | |                 |
2026-02-13 00:22:20.081375 | controller -> localhost | |                 |
2026-02-13 00:22:20.081404 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:22:20.081472 | controller -> localhost | ok: Runtime: 0:00:00.148395
2026-02-13 00:22:20.092018 | 
2026-02-13 00:22:20.092138 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:22:20.127483 | controller | ok
2026-02-13 00:22:20.143987 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:22:20.157233 | 
2026-02-13 00:22:20.157482 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:22:20.183637 | controller | skipping: Conditional result was False
2026-02-13 00:22:20.191974 | 
2026-02-13 00:22:20.192190 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:22:21.264918 | controller | changed
2026-02-13 00:22:21.281351 | 
2026-02-13 00:22:21.281583 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:22:21.949884 | controller | ok
2026-02-13 00:22:21.971517 | 
2026-02-13 00:22:21.971734 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:22:25.083945 | controller | changed
2026-02-13 00:22:25.098061 | 
2026-02-13 00:22:25.098224 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:22:28.184040 | controller | changed
2026-02-13 00:22:28.192501 | 
2026-02-13 00:22:28.192591 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:22:28.219519 | controller | skipping: Conditional result was False
2026-02-13 00:22:28.229709 | 
2026-02-13 00:22:28.229834 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:22:28.718898 | controller -> localhost | changed
2026-02-13 00:22:28.744786 | 
2026-02-13 00:22:28.744956 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:22:29.050880 | controller -> localhost | Identity added: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_rsa (zuul-build-sshkey)
2026-02-13 00:22:29.051251 | controller -> localhost | ok: Runtime: 0:00:00.015746
2026-02-13 00:22:29.061500 | 
2026-02-13 00:22:29.061603 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:22:30.046197 | controller | ok
2026-02-13 00:22:30.054469 | 
2026-02-13 00:22:30.054603 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:22:30.078899 | controller | skipping: Conditional result was False
2026-02-13 00:22:30.090781 | 
2026-02-13 00:22:30.090900 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-13 00:22:30.113559 | controller | ok
2026-02-13 00:22:30.136643 | 
2026-02-13 00:22:30.136769 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:22:30.405535 | controller -> localhost | ok
2026-02-13 00:22:30.417500 | 
2026-02-13 00:22:30.417647 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:22:30.459167 | controller | ok
2026-02-13 00:22:30.476961 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:22:30.487182 | 
2026-02-13 00:22:30.487399 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:22:30.842395 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-13 00:22:30.842782 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_ecdsa.
2026-02-13 00:22:30.842830 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_ecdsa.pub.
2026-02-13 00:22:30.842871 | controller -> localhost | The key fingerprint is:
2026-02-13 00:22:30.842900 | controller -> localhost | SHA256:/GIAVjHRqVUlEzp92bBg6D2W7Ehvco24cmFZAWlGvGk zuul-build-sshkey
2026-02-13 00:22:30.842928 | controller -> localhost | The key's randomart image is:
2026-02-13 00:22:30.842953 | controller -> localhost | +---[ECDSA 521]---+
2026-02-13 00:22:30.842979 | controller -> localhost | |      =*o*Boo    |
2026-02-13 00:22:30.843004 | controller -> localhost | |     . .X+.+ =   |
2026-02-13 00:22:30.843029 | controller -> localhost | |    o  *o=.o+ .  |
2026-02-13 00:22:30.843053 | controller -> localhost | |   . ...E.B.     |
2026-02-13 00:22:30.843077 | controller -> localhost | |      .oSO +     |
2026-02-13 00:22:30.843101 | controller -> localhost | |       .B.* .    |
2026-02-13 00:22:30.843124 | controller -> localhost | |       .o*.      |
2026-02-13 00:22:30.843148 | controller -> localhost | |      ..o.       |
2026-02-13 00:22:30.843172 | controller -> localhost | |       o         |
2026-02-13 00:22:30.843196 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:22:30.843266 | controller -> localhost | ok: Runtime: 0:00:00.010114
2026-02-13 00:22:30.853633 | 
2026-02-13 00:22:30.853763 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:22:30.890457 | controller | ok
2026-02-13 00:22:30.943498 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:22:30.952579 | 
2026-02-13 00:22:30.952647 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:22:30.977639 | controller | skipping: Conditional result was False
2026-02-13 00:22:30.985208 | 
2026-02-13 00:22:30.985274 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:22:31.946609 | controller | changed
2026-02-13 00:22:31.962586 | 
2026-02-13 00:22:31.962844 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:22:32.647856 | controller | ok
2026-02-13 00:22:32.661726 | 
2026-02-13 00:22:32.661909 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:22:35.706473 | controller | changed
2026-02-13 00:22:35.720304 | 
2026-02-13 00:22:35.720448 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:22:38.771803 | controller | changed
2026-02-13 00:22:38.787879 | 
2026-02-13 00:22:38.788097 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:22:38.816176 | controller | skipping: Conditional result was False
2026-02-13 00:22:38.831519 | 
2026-02-13 00:22:38.831708 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:22:39.106868 | controller -> localhost | changed
2026-02-13 00:22:39.138644 | 
2026-02-13 00:22:39.138974 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:22:39.462590 | controller -> localhost | Identity added: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/b13d6a8d90c54877ae27ab6df0d07c80_id_ecdsa (zuul-build-sshkey)
2026-02-13 00:22:39.462913 | controller -> localhost | ok: Runtime: 0:00:00.012865
2026-02-13 00:22:39.472205 | 
2026-02-13 00:22:39.472293 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:22:40.220532 | controller | ok
2026-02-13 00:22:40.241037 | 
2026-02-13 00:22:40.241332 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:22:40.281648 | controller | skipping: Conditional result was False
2026-02-13 00:22:40.310839 | 
2026-02-13 00:22:40.310990 | TASK [include_role : remove-zuul-sshkey]
2026-02-13 00:22:40.337472 | controller | skipping: Conditional result was False
2026-02-13 00:22:40.346861 | 
2026-02-13 00:22:40.346955 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-13 00:22:41.022371 | controller | ok: "logs"
2026-02-13 00:22:41.022637 | controller | ok: All items complete
2026-02-13 00:22:41.022716 | 
2026-02-13 00:22:41.671025 | controller | ok: "artifacts"
2026-02-13 00:22:42.305570 | controller | ok: "docs"
2026-02-13 00:22:42.323590 | 
2026-02-13 00:22:42.323795 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-13 00:22:43.055628 | controller | changed: "logs"
2026-02-13 00:22:43.701971 | controller | changed: "artifacts"
2026-02-13 00:22:44.372273 | controller | changed: "docs"
2026-02-13 00:22:44.427826 | 
2026-02-13 00:22:44.427957 | PLAY RECAP
2026-02-13 00:22:44.428016 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-13 00:22:44.428051 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-13 00:22:44.428075 | 
2026-02-13 00:22:44.587482 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:22:44.589345 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:22:45.219879 | 
2026-02-13 00:22:45.220019 | PLAY [all]
2026-02-13 00:22:45.243557 | 
2026-02-13 00:22:45.243724 | TASK [Install binary dependencies]
2026-02-13 00:22:45.334646 | controller | ok
2026-02-13 00:22:45.355768 | 
2026-02-13 00:22:45.355918 | TASK [bindep : Include find tasks]
2026-02-13 00:22:45.386380 | controller | ok
2026-02-13 00:22:45.394145 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-13 00:22:45.400661 | 
2026-02-13 00:22:45.400753 | TASK [bindep : Look for bindep.txt]
2026-02-13 00:22:46.372637 | controller | ok
2026-02-13 00:22:46.386133 | 
2026-02-13 00:22:46.386307 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:22:46.404569 | controller | skipping: Conditional result was False
2026-02-13 00:22:46.419225 | 
2026-02-13 00:22:46.419433 | TASK [bindep : Look for other-requirements.txt]
2026-02-13 00:22:47.084417 | controller | ok
2026-02-13 00:22:47.101726 | 
2026-02-13 00:22:47.101971 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:22:47.140732 | controller | skipping: Conditional result was False
2026-02-13 00:22:47.155802 | 
2026-02-13 00:22:47.156026 | TASK [bindep : Look for bindep fallback file]
2026-02-13 00:22:47.194119 | controller | skipping: Conditional result was False
2026-02-13 00:22:47.202753 | 
2026-02-13 00:22:47.202853 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:22:47.228334 | controller | skipping: Conditional result was False
2026-02-13 00:22:47.243224 | 
2026-02-13 00:22:47.243458 | TASK [bindep : Include bindep tasks]
2026-02-13 00:22:47.271248 | controller | skipping: Conditional result was False
2026-02-13 00:22:47.280757 | 
2026-02-13 00:22:47.281087 | TASK [bindep : Include install tasks]
2026-02-13 00:22:47.306828 | controller | skipping: Conditional result was False
2026-02-13 00:22:47.316259 | 
2026-02-13 00:22:47.316400 | LOOP [bindep : Include package tasks]
2026-02-13 00:22:47.385542 | 
2026-02-13 00:22:47.385731 | TASK [Run test-setup role]
2026-02-13 00:22:47.406424 | controller | ok
2026-02-13 00:22:47.428930 | 
2026-02-13 00:22:47.429090 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-13 00:22:48.185229 | controller | ok
2026-02-13 00:22:48.200945 | 
2026-02-13 00:22:48.201153 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-13 00:22:48.574431 | controller | skipping: Conditional result was False
2026-02-13 00:22:48.603934 | 
2026-02-13 00:22:48.604064 | PLAY RECAP
2026-02-13 00:22:48.604118 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:22:48.604139 | 
2026-02-13 00:22:48.726895 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:22:48.728739 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:22:49.288298 | 
2026-02-13 00:22:49.288431 | PLAY [controller]
2026-02-13 00:22:49.307996 | 
2026-02-13 00:22:49.308079 | TASK [Create the /root directory]
2026-02-13 00:22:50.458438 | controller | ok
2026-02-13 00:22:50.471355 | 
2026-02-13 00:22:50.471526 | TASK [Install glibc-langpack-en]
2026-02-13 00:22:59.303639 | controller | ok: Nothing to do
2026-02-13 00:22:59.317545 | 
2026-02-13 00:22:59.317754 | TASK [Ensure controller directory exists]
2026-02-13 00:23:00.166027 | controller | changed
2026-02-13 00:23:00.175650 | 
2026-02-13 00:23:00.175795 | TASK [Install container runtime]
2026-02-13 00:23:00.219397 | controller | ok
2026-02-13 00:23:00.253264 | 
2026-02-13 00:23:00.253384 | LOOP [ensure-podman : Find distribution installation]
2026-02-13 00:23:00.281611 | controller | ok: "/var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-13 00:23:00.297623 | controller | included: /var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-13 00:23:00.304992 | 
2026-02-13 00:23:00.305117 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-13 00:25:06.077000 | controller | changed
2026-02-13 00:25:06.091574 | 
2026-02-13 00:25:06.091746 | TASK [ensure-podman : Fetch podman version]
2026-02-13 00:25:07.251012 | controller | Client:       Podman Engine
2026-02-13 00:25:07.251127 | controller | Version:      4.6.2
2026-02-13 00:25:07.251173 | controller | API Version:  4.6.2
2026-02-13 00:25:07.251226 | controller | Go Version:   go1.19.12
2026-02-13 00:25:07.251282 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:25:07.251324 | controller | OS/Arch:      linux/amd64
2026-02-13 00:25:07.467424 | controller | ok: Runtime: 0:00:00.274919
2026-02-13 00:25:07.483456 | 
2026-02-13 00:25:07.483623 | TASK [ensure-podman : Print podman version installed]
2026-02-13 00:25:07.526997 | Podman version: Client:       Podman Engine
2026-02-13 00:25:07.527275 | Version:      4.6.2
2026-02-13 00:25:07.527338 | API Version:  4.6.2
2026-02-13 00:25:07.527383 | Go Version:   go1.19.12
2026-02-13 00:25:07.527424 | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:25:07.527464 | OS/Arch:      linux/amd64
2026-02-13 00:25:07.540474 | 
2026-02-13 00:25:07.540858 | TASK [ensure-podman : Validate podman engine]
2026-02-13 00:25:07.908738 | controller | skipping: Conditional result was False
2026-02-13 00:25:07.925493 | 
2026-02-13 00:25:07.925692 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-13 00:25:07.954028 | controller | skipping: Conditional result was False
2026-02-13 00:25:07.982742 | 
2026-02-13 00:25:07.982941 | TASK [Ensure python3.8 is present]
2026-02-13 00:25:08.010496 | controller | skipping: Conditional result was False
2026-02-13 00:25:08.021442 | 
2026-02-13 00:25:08.021536 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-13 00:25:08.045575 | controller | ok
2026-02-13 00:25:08.075479 | 
2026-02-13 00:25:08.075610 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-13 00:25:11.827695 | controller | ok: Nothing to do
2026-02-13 00:25:11.836010 | 
2026-02-13 00:25:11.836503 | TASK [our-ensure-python : Also install python3-devel]
2026-02-13 00:25:26.742052 | controller | changed
2026-02-13 00:25:26.769442 | 
2026-02-13 00:25:26.770217 | TASK [Run ensure-virtualenv role]
2026-02-13 00:25:26.808168 | controller | ok
2026-02-13 00:25:26.841477 | 
2026-02-13 00:25:26.841774 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-13 00:25:27.664061 | controller | /usr/bin/virtualenv
2026-02-13 00:25:28.261014 | controller | ok: Runtime: 0:00:00.004596
2026-02-13 00:25:28.278866 | 
2026-02-13 00:25:28.279098 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-13 00:25:28.322755 | controller | skipping: Conditional result was False
2026-02-13 00:25:28.323265 | controller | ok: All items complete
2026-02-13 00:25:28.323330 | 
2026-02-13 00:25:28.356556 | 
2026-02-13 00:25:28.356766 | TASK [Find the full path of the Python interpreter]
2026-02-13 00:25:29.181755 | controller | /usr/bin/python3
2026-02-13 00:25:29.737372 | controller | ok
2026-02-13 00:25:29.752884 | 
2026-02-13 00:25:29.753061 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-13 00:25:31.677445 | controller | created virtual environment CPython3.11.0.final.0-64 in 838ms
2026-02-13 00:25:31.739258 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-13 00:25:31.739286 | 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-13 00:25:31.739297 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-13 00:25:31.739314 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-13 00:25:32.140262 | controller | changed
2026-02-13 00:25:32.153313 | 
2026-02-13 00:25:32.153446 | TASK [Set selinux package]
2026-02-13 00:25:32.195256 | controller | ok
2026-02-13 00:25:32.206501 | 
2026-02-13 00:25:32.206639 | TASK [Set selinux package (Fedora)]
2026-02-13 00:25:32.267779 | controller | ok
2026-02-13 00:25:32.275432 | 
2026-02-13 00:25:32.275523 | TASK [Install selinux into virtualenv]
2026-02-13 00:25:35.519571 | controller | Collecting selinux-please-lie-to-me
2026-02-13 00:25:35.662211 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-13 00:25:36.161916 | controller | Collecting setuptools<50.0.0
2026-02-13 00:25:36.168439 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-13 00:25:36.217461 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 18.2 MB/s eta 0:00:00
2026-02-13 00:25:36.351724 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-13 00:25:36.351947 | controller |   Attempting uninstall: setuptools
2026-02-13 00:25:36.355619 | controller |     Found existing installation: setuptools 62.6.0
2026-02-13 00:25:36.450373 | controller |     Uninstalling setuptools-62.6.0:
2026-02-13 00:25:36.465561 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-13 00:25:37.254423 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-13 00:25:37.480803 | controller |
2026-02-13 00:25:37.785485 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:25:37.785532 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:25:38.160802 | controller | ok: Runtime: 0:00:04.633550
2026-02-13 00:25:38.167730 | 
2026-02-13 00:25:38.167801 | TASK [Install pytest-forked into virtualenv]
2026-02-13 00:25:39.698291 | controller | Collecting pytest-forked
2026-02-13 00:25:39.759612 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-13 00:25:39.822763 | controller | Collecting py
2026-02-13 00:25:39.827195 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-13 00:25:39.858080 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.3 MB/s eta 0:00:00
2026-02-13 00:25:40.035884 | controller | Collecting pytest>=3.10
2026-02-13 00:25:40.041569 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-13 00:25:40.065564 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.4 MB/s eta 0:00:00
2026-02-13 00:25:40.138150 | controller | Collecting iniconfig>=1.0.1
2026-02-13 00:25:40.145179 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-13 00:25:40.229289 | controller | Collecting packaging>=22
2026-02-13 00:25:40.236170 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-13 00:25:40.258000 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 3.7 MB/s eta 0:00:00
2026-02-13 00:25:40.302076 | controller | Collecting pluggy<2,>=1.5
2026-02-13 00:25:40.306598 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-13 00:25:40.379615 | controller | Collecting pygments>=2.7.2
2026-02-13 00:25:40.385125 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-13 00:25:40.435132 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 29.5 MB/s eta 0:00:00
2026-02-13 00:25:40.607332 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-13 00:25:43.104221 | 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-13 00:25:43.123539 | controller |
2026-02-13 00:25:43.404039 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:25:43.404078 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:25:43.572240 | controller | ok: Runtime: 0:00:04.413906
2026-02-13 00:25:43.579071 | 
2026-02-13 00:25:43.579221 | TASK [Update pip]
2026-02-13 00:25:44.932484 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-13 00:25:45.200875 | controller | Collecting pip
2026-02-13 00:25:45.278349 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-13 00:25:45.370793 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 20.5 MB/s eta 0:00:00
2026-02-13 00:25:45.485404 | controller | Installing collected packages: pip
2026-02-13 00:25:45.485744 | controller |   Attempting uninstall: pip
2026-02-13 00:25:45.488929 | controller |     Found existing installation: pip 22.2.2
2026-02-13 00:25:45.726464 | controller |     Uninstalling pip-22.2.2:
2026-02-13 00:25:45.753744 | controller |       Successfully uninstalled pip-22.2.2
2026-02-13 00:25:47.845955 | controller | Successfully installed pip-26.0.1
2026-02-13 00:25:48.450250 | controller | ok: Runtime: 0:00:03.776482
2026-02-13 00:25:48.459393 | 
2026-02-13 00:25:48.459535 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-13 00:25:49.389125 | controller | changed
2026-02-13 00:25:49.402450 | 
2026-02-13 00:25:49.402589 | TASK [Install ansible into virtualenv]
2026-02-13 00:25:50.741663 | controller | Processing ./src/github.com/ansible/ansible
2026-02-13 00:25:50.752008 | controller |   Installing build dependencies: started
2026-02-13 00:25:52.511688 | controller |   Installing build dependencies: finished with status 'done'
2026-02-13 00:25:52.512554 | controller |   Getting requirements to build wheel: started
2026-02-13 00:25:54.061538 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-13 00:25:54.064838 | controller |   Preparing metadata (pyproject.toml): started
2026-02-13 00:25:54.977592 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-13 00:25:54.980996 | 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-13 00:25:54.984681 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-13 00:25:55.320894 | controller | ERROR
2026-02-13 00:25:55.321154 | controller | {
2026-02-13 00:25:55.321215 | controller |   "delta": "0:00:05.049849",
2026-02-13 00:25:55.321257 | controller |   "end": "2026-02-13 00:25:55.150388",
2026-02-13 00:25:55.321293 | controller |   "msg": "non-zero return code",
2026-02-13 00:25:55.321353 | controller |   "rc": 1,
2026-02-13 00:25:55.321389 | controller |   "start": "2026-02-13 00:25:50.100539"
2026-02-13 00:25:55.321422 | controller | }
failure
2026-02-13 00:25:55.324187 | 
2026-02-13 00:25:55.324290 | PLAY RECAP
2026-02-13 00:25:55.324380 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-13 00:25:55.324562 | 
2026-02-13 00:25:55.463653 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:25:55.465880 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:25:56.134400 | 
2026-02-13 00:25:56.134554 | PLAY [all]
2026-02-13 00:25:56.156701 | 
2026-02-13 00:25:56.156820 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-13 00:25:58.030455 | controller | changed: non-zero return code
2026-02-13 00:25:58.043807 | 
2026-02-13 00:25:58.043981 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-13 00:25:58.063249 | controller | skipping: Conditional result was False
2026-02-13 00:25:58.080789 | 
2026-02-13 00:25:58.080969 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-13 00:25:58.117074 | 
2026-02-13 00:25:58.117335 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-13 00:25:58.155036 | 
2026-02-13 00:25:58.155318 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-13 00:25:58.182094 | controller | skipping: Conditional result was False
2026-02-13 00:25:58.192122 | 
2026-02-13 00:25:58.192248 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-13 00:25:58.232417 | 
2026-02-13 00:25:58.232699 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-13 00:25:58.261325 | controller | skipping: Conditional result was False
2026-02-13 00:25:58.270329 | 
2026-02-13 00:25:58.270429 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-13 00:25:58.286409 | controller | skipping: Conditional result was False
2026-02-13 00:25:58.296276 | 
2026-02-13 00:25:58.296377 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-13 00:25:58.312429 | controller | skipping: Conditional result was False
2026-02-13 00:25:58.352825 | 
2026-02-13 00:25:58.352946 | PLAY RECAP
2026-02-13 00:25:58.353011 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:25:58.353040 | 
2026-02-13 00:25:58.516596 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:25:58.518405 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-13 00:25:59.142078 | 
2026-02-13 00:25:59.142245 | PLAY [all:!appliance*]
2026-02-13 00:25:59.165138 | 
2026-02-13 00:25:59.165240 | TASK [unregister the node]
2026-02-13 00:25:59.520036 | controller | skipping: Conditional result was False
2026-02-13 00:25:59.538291 | 
2026-02-13 00:25:59.538526 | TASK [include_role : fetch-output]
2026-02-13 00:25:59.586100 | controller | ok
2026-02-13 00:25:59.624289 | 
2026-02-13 00:25:59.624487 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-13 00:25:59.702238 | controller | skipping: Conditional result was False
2026-02-13 00:25:59.711602 | 
2026-02-13 00:25:59.711756 | TASK [fetch-output : Set log path for single node]
2026-02-13 00:25:59.754524 | controller | ok
2026-02-13 00:25:59.760851 | 
2026-02-13 00:25:59.760987 | LOOP [fetch-output : Ensure local output dirs]
2026-02-13 00:26:00.201831 | controller -> localhost | ok: "/var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/logs"
2026-02-13 00:26:00.458188 | controller -> localhost | changed: "/var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/artifacts"
2026-02-13 00:26:00.710929 | controller -> localhost | changed: "/var/lib/zuul/builds/b13d6a8d90c54877ae27ab6df0d07c80/work/docs"
2026-02-13 00:26:00.731517 | 
2026-02-13 00:26:00.731710 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-13 00:26:02.931189 | controller | changed:
2026-02-13 00:26:02.931463 | controller | .d..t...... ./
2026-02-13 00:26:02.931496 | controller | cd+++++++++ controller/
2026-02-13 00:26:02.931534 | controller | changed: All items complete
2026-02-13 00:26:02.931557 | 
2026-02-13 00:26:05.037884 | controller | changed: .d..t...... ./
2026-02-13 00:26:07.155301 | controller | changed: .d..t...... ./
2026-02-13 00:26:07.195288 | 
2026-02-13 00:26:07.195534 | TASK [include_role : fetch-output-openshift]
2026-02-13 00:26:07.224012 | controller | skipping: Conditional result was False
2026-02-13 00:26:07.236251 | 
2026-02-13 00:26:07.236367 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-13 00:26:07.283836 | controller | skipping: Conditional result was False
2026-02-13 00:26:07.295766 | controller | skipping: Conditional result was False
2026-02-13 00:26:07.337801 | 
2026-02-13 00:26:07.338000 | PLAY [localhost]
2026-02-13 00:26:07.357181 | 
2026-02-13 00:26:07.357279 | TASK [Run Zuul manifest role]
2026-02-13 00:26:07.381015 | localhost | ok
2026-02-13 00:26:07.400115 | 
2026-02-13 00:26:07.400208 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-13 00:26:07.860045 | localhost | changed
2026-02-13 00:26:07.865220 | 
2026-02-13 00:26:07.865286 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-13 00:26:07.910542 | localhost | ok
2026-02-13 00:26:07.927558 | 
2026-02-13 00:26:07.927645 | TASK [Set zuul-log-path fact]
2026-02-13 00:26:07.998838 | localhost | ok
2026-02-13 00:26:08.020261 | 
2026-02-13 00:26:08.020444 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:26:08.063830 | localhost | ok
2026-02-13 00:26:08.075892 | 
2026-02-13 00:26:08.075987 | LOOP [Run upload-logs-swift role]
2026-02-13 00:26:08.123147 | localhost | Output suppressed because no_log was given
2026-02-13 00:26:08.178719 | 
2026-02-13 00:26:08.178882 | TASK [Set zuul-log-path fact]
2026-02-13 00:26:08.225655 | localhost | skipping: Conditional result was False
2026-02-13 00:26:08.237326 | 
2026-02-13 00:26:08.237477 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-13 00:26:08.743052 | localhost -> localhost | ok: Runtime: 0:00:00.009343
2026-02-13 00:26:08.749510 | 
2026-02-13 00:26:08.749641 | TASK [upload-logs-swift : Upload logs to swift]