2026-02-07 00:25:40.525723 | Job console starting...
2026-02-07 00:25:40.536075 | Updating repositories
2026-02-07 00:25:40.681233 | Preparing job workspace
2026-02-07 00:25:49.260183 | Running Ansible setup...
2026-02-07 00:25:53.942611 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-07 00:25:54.519020 | 
2026-02-07 00:25:54.519150 | PLAY [localhost]
2026-02-07 00:25:54.527693 | 
2026-02-07 00:25:54.527767 | TASK [Gathering Facts]
2026-02-07 00:25:55.525988 | localhost | ok
2026-02-07 00:25:55.540759 | 
2026-02-07 00:25:55.540911 | TASK [Setup log path fact]
2026-02-07 00:25:55.560504 | localhost | ok
2026-02-07 00:25:55.578998 | 
2026-02-07 00:25:55.579071 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-07 00:25:55.607218 | localhost | ok
2026-02-07 00:25:55.615316 | 
2026-02-07 00:25:55.615404 | TASK [emit-job-header : Print job information]
2026-02-07 00:25:55.663966 | # Job Information
2026-02-07 00:25:55.664082 | Ansible Version: 2.15.12
2026-02-07 00:25:55.664113 | Job: ansible-test-sanity-docker-milestone
2026-02-07 00:25:55.664133 | Pipeline: periodic
2026-02-07 00:25:55.664151 | Executor: ze04.softwarefactory-project.io
2026-02-07 00:25:55.664169 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-07 00:25:55.664190 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0e3/ansible/0e34c8ffa93545dd8e39d9d682243f1d/
2026-02-07 00:25:55.664209 | Event ID: debcfade88c04063a6272a678728f719
2026-02-07 00:25:55.667881 | 
2026-02-07 00:25:55.667942 | LOOP [emit-job-header : Print node information]
2026-02-07 00:25:55.767329 | localhost | ok:
2026-02-07 00:25:55.767562 | localhost | # Node Information
2026-02-07 00:25:55.767590 | localhost | Inventory Hostname: controller
2026-02-07 00:25:55.767610 | localhost | Hostname: np0005611430
2026-02-07 00:25:55.767629 | localhost | Username: zuul
2026-02-07 00:25:55.767649 | localhost | Distro: Fedora 37
2026-02-07 00:25:55.767667 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-07 00:25:55.767705 | localhost | Region: ca-ymq-1
2026-02-07 00:25:55.767724 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-07 00:25:55.767740 | localhost | Product Name: OpenStack Nova
2026-02-07 00:25:55.767758 | localhost | Interface IP: 162.253.55.12
2026-02-07 00:25:55.780392 | 
2026-02-07 00:25:55.780492 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-07 00:25:56.176337 | localhost -> localhost | changed
2026-02-07 00:25:56.196362 | 
2026-02-07 00:25:56.196503 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-07 00:25:57.048644 | localhost -> localhost | changed
2026-02-07 00:25:57.082151 | 
2026-02-07 00:25:57.082302 | PLAY [all:!appliance*]
2026-02-07 00:25:57.110647 | 
2026-02-07 00:25:57.110907 | TASK [include_role : start-zuul-console]
2026-02-07 00:25:57.135236 | controller | ok
2026-02-07 00:25:57.166236 | 
2026-02-07 00:25:57.166426 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-07 00:25:57.611532 | controller | ok
2026-02-07 00:25:57.644071 | 
2026-02-07 00:25:57.644172 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-07 00:25:58.673331 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-07 00:25:58.686860 | 
2026-02-07 00:25:58.686994 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-07 00:25:59.230341 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.243510 | 
2026-02-07 00:25:59.243651 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-07 00:25:59.280829 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.293609 | 
2026-02-07 00:25:59.293787 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-07 00:25:59.321279 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.335052 | 
2026-02-07 00:25:59.335193 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-07 00:25:59.372441 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.385055 | 
2026-02-07 00:25:59.385199 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-07 00:25:59.423396 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.437223 | 
2026-02-07 00:25:59.437371 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-07 00:25:59.454267 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.470820 | 
2026-02-07 00:25:59.470912 | TASK [Disable Fedora Modular]
2026-02-07 00:25:59.718161 | controller | changed
2026-02-07 00:25:59.735038 | 
2026-02-07 00:25:59.735137 | TASK [Enable EPEL]
2026-02-07 00:25:59.770916 | controller | skipping: Conditional result was False
2026-02-07 00:25:59.777723 | 
2026-02-07 00:25:59.777795 | TASK [Register the RHEL node]
2026-02-07 00:26:00.316402 | 
2026-02-07 00:26:00.316613 | TASK [Show the subscription-manager status]
2026-02-07 00:26:00.891000 | controller | skipping: Conditional result was False
2026-02-07 00:26:00.908116 | 
2026-02-07 00:26:00.908318 | TASK [Enable EPEL on RHEL]
2026-02-07 00:26:01.464855 | controller | skipping: Conditional result was False
2026-02-07 00:26:01.473203 | 
2026-02-07 00:26:01.473311 | TASK [Install git and tox]
2026-02-07 00:27:27.802120 | controller | changed
2026-02-07 00:27:27.810562 | 
2026-02-07 00:27:27.810641 | TASK [include_role : prepare-workspace]
2026-02-07 00:27:27.842879 | controller | ok
2026-02-07 00:27:27.870955 | 
2026-02-07 00:27:27.871096 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-07 00:27:28.098051 | controller | ok
2026-02-07 00:27:28.106507 | 
2026-02-07 00:27:28.106597 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-07 00:27:40.473002 | controller | Output suppressed because no_log was given
2026-02-07 00:27:40.539695 | 
2026-02-07 00:27:40.539872 | TASK [include_role : prepare-workspace-openshift]
2026-02-07 00:27:40.582045 | controller | skipping: Conditional result was False
2026-02-07 00:27:40.606465 | 
2026-02-07 00:27:40.606556 | PLAY [all:!appliance]
2026-02-07 00:27:40.623857 | 
2026-02-07 00:27:40.623945 | TASK [Run add-build-sshkey role (RSA)]
2026-02-07 00:27:40.660011 | controller | ok
2026-02-07 00:27:40.675595 | 
2026-02-07 00:27:40.675723 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-07 00:27:40.979964 | controller -> localhost | ok
2026-02-07 00:27:40.993393 | 
2026-02-07 00:27:40.993524 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-07 00:27:41.033360 | controller | ok
2026-02-07 00:27:41.061502 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-07 00:27:41.069758 | 
2026-02-07 00:27:41.069840 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-07 00:27:41.643085 | controller -> localhost | Generating public/private rsa key pair.
2026-02-07 00:27:41.643323 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_rsa.
2026-02-07 00:27:41.643359 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_rsa.pub.
2026-02-07 00:27:41.643387 | controller -> localhost | The key fingerprint is:
2026-02-07 00:27:41.643412 | controller -> localhost | SHA256:/buXjygXrebsOPYjUtSzLyVDPJXHblgpJkTKB2u28sY zuul-build-sshkey
2026-02-07 00:27:41.643436 | controller -> localhost | The key's randomart image is:
2026-02-07 00:27:41.643461 | controller -> localhost | +---[RSA 2048]----+
2026-02-07 00:27:41.643484 | controller -> localhost | |         .oo   o.|
2026-02-07 00:27:41.643507 | controller -> localhost | |        . +. oo.+|
2026-02-07 00:27:41.643530 | controller -> localhost | |         * +o..= |
2026-02-07 00:27:41.643551 | controller -> localhost | |        o.+ * . o|
2026-02-07 00:27:41.643573 | controller -> localhost | |       .So.. = . |
2026-02-07 00:27:41.643607 | controller -> localhost | |        + ..= o  |
2026-02-07 00:27:41.643638 | controller -> localhost | |         E  .B . |
2026-02-07 00:27:41.643665 | controller -> localhost | |        o =o*o+. |
2026-02-07 00:27:41.643711 | controller -> localhost | |         o.XO=...|
2026-02-07 00:27:41.643741 | controller -> localhost | +----[SHA256]-----+
2026-02-07 00:27:41.643796 | controller -> localhost | ok: Runtime: 0:00:00.129140
2026-02-07 00:27:41.653707 | 
2026-02-07 00:27:41.653792 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-07 00:27:41.674286 | controller | ok
2026-02-07 00:27:41.683722 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-07 00:27:41.692340 | 
2026-02-07 00:27:41.692401 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-07 00:27:41.705717 | controller | skipping: Conditional result was False
2026-02-07 00:27:41.715149 | 
2026-02-07 00:27:41.715248 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-07 00:32:43.632841 | controller | changed
2026-02-07 00:32:43.645154 | 
2026-02-07 00:32:43.645295 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-07 00:32:43.887671 | controller | ok
2026-02-07 00:32:43.900132 | 
2026-02-07 00:32:43.900270 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-07 00:32:44.588158 | controller | changed
2026-02-07 00:32:44.601395 | 
2026-02-07 00:32:44.601531 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-07 00:32:45.233335 | controller | changed
2026-02-07 00:32:45.247704 | 
2026-02-07 00:32:45.247879 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-07 00:32:45.286605 | controller | skipping: Conditional result was False
2026-02-07 00:32:45.302758 | 
2026-02-07 00:32:45.302904 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-07 00:32:45.759739 | controller -> localhost | changed
2026-02-07 00:32:45.784764 | 
2026-02-07 00:32:45.784937 | TASK [add-build-sshkey : Add back temp key]
2026-02-07 00:32:46.091317 | controller -> localhost | Identity added: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_rsa (zuul-build-sshkey)
2026-02-07 00:32:46.091853 | controller -> localhost | ok: Runtime: 0:00:00.013674
2026-02-07 00:32:46.106152 | 
2026-02-07 00:32:46.106289 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-07 00:32:46.455906 | controller | ok
2026-02-07 00:32:46.467809 | 
2026-02-07 00:32:46.468009 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-07 00:32:46.506074 | controller | skipping: Conditional result was False
2026-02-07 00:32:46.532160 | 
2026-02-07 00:32:46.532314 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-07 00:32:46.572032 | controller | ok
2026-02-07 00:32:46.600759 | 
2026-02-07 00:32:46.600882 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-07 00:32:46.914240 | controller -> localhost | ok
2026-02-07 00:32:46.927530 | 
2026-02-07 00:32:46.927654 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-07 00:32:46.952802 | controller | ok
2026-02-07 00:32:46.969213 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-07 00:32:46.978275 | 
2026-02-07 00:32:46.978375 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-07 00:32:47.335311 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-07 00:32:47.335755 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_ecdsa.
2026-02-07 00:32:47.335842 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_ecdsa.pub.
2026-02-07 00:32:47.335917 | controller -> localhost | The key fingerprint is:
2026-02-07 00:32:47.335972 | controller -> localhost | SHA256:gyHCkLnuiWXSFx4XiCDsCIV4d1O3axkp0xr86R94Buc zuul-build-sshkey
2026-02-07 00:32:47.336027 | controller -> localhost | The key's randomart image is:
2026-02-07 00:32:47.336083 | controller -> localhost | +---[ECDSA 521]---+
2026-02-07 00:32:47.336133 | controller -> localhost | |**.. . .. .      |
2026-02-07 00:32:47.336183 | controller -> localhost | |B+o o +. o o     |
2026-02-07 00:32:47.336232 | controller -> localhost | |+oo....o= =      |
2026-02-07 00:32:47.336281 | controller -> localhost | |o. .o..o * =     |
2026-02-07 00:32:47.336328 | controller -> localhost | |.. . +. S B .    |
2026-02-07 00:32:47.336376 | controller -> localhost | |..+ o    + =     |
2026-02-07 00:32:47.336424 | controller -> localhost | |o+..      o E    |
2026-02-07 00:32:47.336472 | controller -> localhost | |.o         + .   |
2026-02-07 00:32:47.336518 | controller -> localhost | |            .    |
2026-02-07 00:32:47.336565 | controller -> localhost | +----[SHA256]-----+
2026-02-07 00:32:47.336728 | controller -> localhost | ok: Runtime: 0:00:00.015632
2026-02-07 00:32:47.356951 | 
2026-02-07 00:32:47.357113 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-07 00:32:47.427455 | controller | ok
2026-02-07 00:32:47.434855 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-07 00:32:47.443128 | 
2026-02-07 00:32:47.443187 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-07 00:32:47.467631 | controller | skipping: Conditional result was False
2026-02-07 00:32:47.473787 | 
2026-02-07 00:32:47.473852 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-07 00:32:47.745507 | controller | changed
2026-02-07 00:32:47.759326 | 
2026-02-07 00:32:47.759462 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-07 00:32:47.971859 | controller | ok
2026-02-07 00:32:47.984742 | 
2026-02-07 00:32:47.984895 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-07 00:32:48.591074 | controller | changed
2026-02-07 00:32:48.598930 | 
2026-02-07 00:32:48.599016 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-07 00:32:49.240597 | controller | changed
2026-02-07 00:32:49.252976 | 
2026-02-07 00:32:49.253108 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-07 00:32:49.280646 | controller | skipping: Conditional result was False
2026-02-07 00:32:49.293955 | 
2026-02-07 00:32:49.294091 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-07 00:32:49.545760 | controller -> localhost | changed
2026-02-07 00:32:49.572360 | 
2026-02-07 00:32:49.572516 | TASK [add-build-sshkey : Add back temp key]
2026-02-07 00:32:49.835150 | controller -> localhost | Identity added: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/0e34c8ffa93545dd8e39d9d682243f1d_id_ecdsa (zuul-build-sshkey)
2026-02-07 00:32:49.835587 | controller -> localhost | ok: Runtime: 0:00:00.013436
2026-02-07 00:32:49.852974 | 
2026-02-07 00:32:49.853138 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-07 00:32:50.067592 | controller | ok
2026-02-07 00:32:50.079980 | 
2026-02-07 00:32:50.080129 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-07 00:32:50.117503 | controller | skipping: Conditional result was False
2026-02-07 00:32:50.128662 | 
2026-02-07 00:32:50.128748 | TASK [include_role : remove-zuul-sshkey]
2026-02-07 00:32:50.152881 | controller | skipping: Conditional result was False
2026-02-07 00:32:50.158898 | 
2026-02-07 00:32:50.158961 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-07 00:32:50.403248 | controller | ok: "logs"
2026-02-07 00:32:50.403874 | controller | ok: All items complete
2026-02-07 00:32:50.403949 | 
2026-02-07 00:32:50.591314 | controller | ok: "artifacts"
2026-02-07 00:32:50.781979 | controller | ok: "docs"
2026-02-07 00:32:50.806773 | 
2026-02-07 00:32:50.806918 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-07 00:32:51.041636 | controller | changed: "logs"
2026-02-07 00:32:51.253277 | controller | changed: "artifacts"
2026-02-07 00:32:51.449184 | controller | changed: "docs"
2026-02-07 00:32:51.509060 | 
2026-02-07 00:32:51.509141 | PLAY RECAP
2026-02-07 00:32:51.509198 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-07 00:32:51.509234 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-07 00:32:51.509259 | 
2026-02-07 00:32:51.620516 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-07 00:32:51.621411 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-07 00:32:52.178121 | 
2026-02-07 00:32:52.178223 | PLAY [all]
2026-02-07 00:32:52.199929 | 
2026-02-07 00:32:52.200009 | TASK [Install binary dependencies]
2026-02-07 00:32:52.243753 | controller | ok
2026-02-07 00:32:52.262976 | 
2026-02-07 00:32:52.263058 | TASK [bindep : Include find tasks]
2026-02-07 00:32:52.303197 | controller | ok
2026-02-07 00:32:52.310986 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-07 00:32:52.317133 | 
2026-02-07 00:32:52.317193 | TASK [bindep : Look for bindep.txt]
2026-02-07 00:32:52.869812 | controller | ok
2026-02-07 00:32:52.878259 | 
2026-02-07 00:32:52.878360 | TASK [bindep : Define bindep_file fact]
2026-02-07 00:32:52.907948 | controller | skipping: Conditional result was False
2026-02-07 00:32:52.921231 | 
2026-02-07 00:32:52.921380 | TASK [bindep : Look for other-requirements.txt]
2026-02-07 00:32:53.161300 | controller | ok
2026-02-07 00:32:53.168695 | 
2026-02-07 00:32:53.168787 | TASK [bindep : Define bindep_file fact]
2026-02-07 00:32:53.204375 | controller | skipping: Conditional result was False
2026-02-07 00:32:53.220643 | 
2026-02-07 00:32:53.220886 | TASK [bindep : Look for bindep fallback file]
2026-02-07 00:32:53.259483 | controller | skipping: Conditional result was False
2026-02-07 00:32:53.277360 | 
2026-02-07 00:32:53.277561 | TASK [bindep : Define bindep_file fact]
2026-02-07 00:32:53.316804 | controller | skipping: Conditional result was False
2026-02-07 00:32:53.330735 | 
2026-02-07 00:32:53.330890 | TASK [bindep : Include bindep tasks]
2026-02-07 00:32:53.358582 | controller | skipping: Conditional result was False
2026-02-07 00:32:53.372023 | 
2026-02-07 00:32:53.372167 | TASK [bindep : Include install tasks]
2026-02-07 00:32:53.399910 | controller | skipping: Conditional result was False
2026-02-07 00:32:53.414384 | 
2026-02-07 00:32:53.414557 | LOOP [bindep : Include package tasks]
2026-02-07 00:32:53.498323 | 
2026-02-07 00:32:53.498641 | TASK [Run test-setup role]
2026-02-07 00:32:53.531108 | controller | ok
2026-02-07 00:32:53.560200 | 
2026-02-07 00:32:53.560351 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-07 00:32:53.770224 | controller | ok
2026-02-07 00:32:53.779163 | 
2026-02-07 00:32:53.779259 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-07 00:32:54.323812 | controller | skipping: Conditional result was False
2026-02-07 00:32:54.376770 | 
2026-02-07 00:32:54.377000 | PLAY RECAP
2026-02-07 00:32:54.377099 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-07 00:32:54.377148 | 
2026-02-07 00:32:54.566652 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-07 00:32:54.568487 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-07 00:32:55.218816 | 
2026-02-07 00:32:55.218970 | PLAY [controller]
2026-02-07 00:32:55.239502 | 
2026-02-07 00:32:55.239608 | TASK [Create the /root directory]
2026-02-07 00:32:55.828657 | controller | ok
2026-02-07 00:32:55.841833 | 
2026-02-07 00:32:55.841994 | TASK [Install glibc-langpack-en]
2026-02-07 00:32:59.983497 | controller | ok: Nothing to do
2026-02-07 00:32:59.999054 | 
2026-02-07 00:32:59.999219 | TASK [Ensure controller directory exists]
2026-02-07 00:33:00.219323 | controller | changed
2026-02-07 00:33:00.227251 | 
2026-02-07 00:33:00.227352 | TASK [Install container runtime]
2026-02-07 00:33:00.310604 | controller | ok
2026-02-07 00:33:00.375115 | 
2026-02-07 00:33:00.375240 | LOOP [ensure-podman : Find distribution installation]
2026-02-07 00:33:00.402190 | controller | ok: "/var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-07 00:33:00.418372 | controller | included: /var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-07 00:33:00.425369 | 
2026-02-07 00:33:00.425466 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-07 00:34:09.496836 | controller | changed
2026-02-07 00:34:09.510445 | 
2026-02-07 00:34:09.510577 | TASK [ensure-podman : Fetch podman version]
2026-02-07 00:34:10.092155 | controller | Client:       Podman Engine
2026-02-07 00:34:10.118254 | controller | Version:      4.6.2
2026-02-07 00:34:10.118311 | controller | API Version:  4.6.2
2026-02-07 00:34:10.118327 | controller | Go Version:   go1.19.12
2026-02-07 00:34:10.118354 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-07 00:34:10.118366 | controller | OS/Arch:      linux/amd64
2026-02-07 00:34:10.560919 | controller | ok: Runtime: 0:00:00.213481
2026-02-07 00:34:10.574199 | 
2026-02-07 00:34:10.574344 | TASK [ensure-podman : Print podman version installed]
2026-02-07 00:34:10.613474 | Podman version: Client:       Podman Engine
2026-02-07 00:34:10.613765 | Version:      4.6.2
2026-02-07 00:34:10.613830 | API Version:  4.6.2
2026-02-07 00:34:10.613875 | Go Version:   go1.19.12
2026-02-07 00:34:10.613918 | Built:        Mon Aug 28 19:38:31 2023
2026-02-07 00:34:10.613960 | OS/Arch:      linux/amd64
2026-02-07 00:34:10.625928 | 
2026-02-07 00:34:10.626076 | TASK [ensure-podman : Validate podman engine]
2026-02-07 00:34:11.174989 | controller | skipping: Conditional result was False
2026-02-07 00:34:11.184661 | 
2026-02-07 00:34:11.184804 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-07 00:34:11.210074 | controller | skipping: Conditional result was False
2026-02-07 00:34:11.237741 | 
2026-02-07 00:34:11.237922 | TASK [Ensure python3.8 is present]
2026-02-07 00:34:11.255490 | controller | skipping: Conditional result was False
2026-02-07 00:34:11.270272 | 
2026-02-07 00:34:11.270424 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-07 00:34:11.306164 | controller | ok
2026-02-07 00:34:11.337520 | 
2026-02-07 00:34:11.337667 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-07 00:34:12.885474 | controller | ok: Nothing to do
2026-02-07 00:34:12.899528 | 
2026-02-07 00:34:12.899739 | TASK [our-ensure-python : Also install python3-devel]
2026-02-07 00:34:21.734375 | controller | changed
2026-02-07 00:34:21.759243 | 
2026-02-07 00:34:21.759333 | TASK [Run ensure-virtualenv role]
2026-02-07 00:34:21.824839 | controller | ok
2026-02-07 00:34:21.846628 | 
2026-02-07 00:34:21.846710 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-07 00:34:22.089739 | controller | /usr/bin/virtualenv
2026-02-07 00:34:22.376512 | controller | ok: Runtime: 0:00:00.005347
2026-02-07 00:34:22.389316 | 
2026-02-07 00:34:22.389452 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-07 00:34:22.426661 | controller | skipping: Conditional result was False
2026-02-07 00:34:22.427164 | controller | ok: All items complete
2026-02-07 00:34:22.427222 | 
2026-02-07 00:34:22.452975 | 
2026-02-07 00:34:22.453134 | TASK [Find the full path of the Python interpreter]
2026-02-07 00:34:22.684050 | controller | /usr/bin/python3
2026-02-07 00:34:22.998499 | controller | ok
2026-02-07 00:34:23.013227 | 
2026-02-07 00:34:23.013492 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-07 00:34:23.933288 | controller | created virtual environment CPython3.11.0.final.0-64 in 552ms
2026-02-07 00:34:23.951430 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-07 00:34:23.951467 | 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-07 00:34:23.951476 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-07 00:34:23.951497 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-07 00:34:24.075827 | controller | changed
2026-02-07 00:34:24.082850 | 
2026-02-07 00:34:24.082955 | TASK [Set selinux package]
2026-02-07 00:34:24.113445 | controller | ok
2026-02-07 00:34:24.118806 | 
2026-02-07 00:34:24.118872 | TASK [Set selinux package (Fedora)]
2026-02-07 00:34:24.158801 | controller | ok
2026-02-07 00:34:24.163748 | 
2026-02-07 00:34:24.163808 | TASK [Install selinux into virtualenv]
2026-02-07 00:34:49.653470 | controller | Collecting selinux-please-lie-to-me
2026-02-07 00:35:01.887296 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-07 00:35:02.200461 | controller | Collecting setuptools<50.0.0
2026-02-07 00:35:02.208292 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-07 00:35:02.267531 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 14.6 MB/s eta 0:00:00
2026-02-07 00:35:02.346637 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-07 00:35:02.346845 | controller |   Attempting uninstall: setuptools
2026-02-07 00:35:02.349218 | controller |     Found existing installation: setuptools 62.6.0
2026-02-07 00:35:02.407727 | controller |     Uninstalling setuptools-62.6.0:
2026-02-07 00:35:02.415379 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-07 00:35:02.784787 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-07 00:35:14.266119 | controller |
2026-02-07 00:35:14.347582 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-07 00:35:14.347626 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-07 00:35:14.717887 | controller | ok: Runtime: 0:00:49.971703
2026-02-07 00:35:14.724289 | 
2026-02-07 00:35:14.724358 | TASK [Install pytest-forked into virtualenv]
2026-02-07 00:35:27.665106 | controller | Collecting pytest-forked
2026-02-07 00:35:39.840488 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-07 00:35:39.882192 | controller | Collecting py
2026-02-07 00:35:39.887895 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-07 00:35:39.904477 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 7.4 MB/s eta 0:00:00
2026-02-07 00:35:40.011701 | controller | Collecting pytest>=3.10
2026-02-07 00:35:40.016198 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-07 00:35:40.032683 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 28.2 MB/s eta 0:00:00
2026-02-07 00:35:40.068321 | controller | Collecting iniconfig>=1.0.1
2026-02-07 00:35:40.072288 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-07 00:35:40.116689 | controller | Collecting packaging>=22
2026-02-07 00:35:40.122348 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-07 00:35:40.128213 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 20.9 MB/s eta 0:00:00
2026-02-07 00:35:40.159103 | controller | Collecting pluggy<2,>=1.5
2026-02-07 00:35:40.162478 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-07 00:35:40.205898 | controller | Collecting pygments>=2.7.2
2026-02-07 00:35:40.211387 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-07 00:35:40.230118 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 74.0 MB/s eta 0:00:00
2026-02-07 00:35:40.298372 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-07 00:35:41.387067 | 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-07 00:35:41.395859 | controller |
2026-02-07 00:35:41.476887 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-07 00:35:41.476920 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-07 00:35:41.775264 | controller | ok: Runtime: 0:00:26.552379
2026-02-07 00:35:41.791398 | 
2026-02-07 00:35:41.791569 | TASK [Update pip]
2026-02-07 00:35:42.354559 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-07 00:35:54.802936 | controller | Collecting pip
2026-02-07 00:36:06.988149 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-07 00:36:07.059610 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 26.4 MB/s eta 0:00:00
2026-02-07 00:36:07.124743 | controller | Installing collected packages: pip
2026-02-07 00:36:07.125379 | controller |   Attempting uninstall: pip
2026-02-07 00:36:07.127043 | controller |     Found existing installation: pip 22.2.2
2026-02-07 00:36:07.271913 | controller |     Uninstalling pip-22.2.2:
2026-02-07 00:36:07.287484 | controller |       Successfully uninstalled pip-22.2.2
2026-02-07 00:36:08.179313 | controller | Successfully installed pip-26.0.1
2026-02-07 00:36:08.406378 | controller | ok: Runtime: 0:00:26.210274
2026-02-07 00:36:08.423385 | 
2026-02-07 00:36:08.423507 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-07 00:36:08.664681 | controller | changed
2026-02-07 00:36:08.672774 | 
2026-02-07 00:36:08.672862 | TASK [Install ansible into virtualenv]
2026-02-07 00:36:09.209361 | controller | Processing ./src/github.com/ansible/ansible
2026-02-07 00:36:09.212401 | controller |   Installing build dependencies: started
2026-02-07 00:36:32.282247 | controller |   Installing build dependencies: finished with status 'done'
2026-02-07 00:36:32.284321 | controller |   Getting requirements to build wheel: started
2026-02-07 00:36:33.039758 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-07 00:36:33.041355 | controller |   Preparing metadata (pyproject.toml): started
2026-02-07 00:36:33.519022 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-07 00:36:33.524060 | 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-07 00:36:33.528261 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-07 00:36:33.730482 | controller | ERROR
2026-02-07 00:36:33.730947 | controller | {
2026-02-07 00:36:33.731021 | controller |   "delta": "0:00:24.703368",
2026-02-07 00:36:33.731068 | controller |   "end": "2026-02-07 00:36:33.601665",
2026-02-07 00:36:33.731108 | controller |   "msg": "non-zero return code",
2026-02-07 00:36:33.731173 | controller |   "rc": 1,
2026-02-07 00:36:33.731212 | controller |   "start": "2026-02-07 00:36:08.898297"
2026-02-07 00:36:33.731247 | controller | }
failure
2026-02-07 00:36:33.734628 | 
2026-02-07 00:36:33.734865 | PLAY RECAP
2026-02-07 00:36:33.734997 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-07 00:36:33.735059 | 
2026-02-07 00:36:33.877996 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-07 00:36:33.880266 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-07 00:36:34.537896 | 
2026-02-07 00:36:34.538018 | PLAY [all]
2026-02-07 00:36:34.559459 | 
2026-02-07 00:36:34.559541 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-07 00:36:35.037412 | controller | changed: non-zero return code
2026-02-07 00:36:35.050583 | 
2026-02-07 00:36:35.050812 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-07 00:36:35.078246 | controller | skipping: Conditional result was False
2026-02-07 00:36:35.092513 | 
2026-02-07 00:36:35.092666 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-07 00:36:35.133617 | 
2026-02-07 00:36:35.133923 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-07 00:36:35.164921 | 
2026-02-07 00:36:35.165191 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-07 00:36:35.181628 | controller | skipping: Conditional result was False
2026-02-07 00:36:35.197595 | 
2026-02-07 00:36:35.197730 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-07 00:36:35.230232 | 
2026-02-07 00:36:35.230404 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-07 00:36:35.255012 | controller | skipping: Conditional result was False
2026-02-07 00:36:35.263222 | 
2026-02-07 00:36:35.263316 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-07 00:36:35.278498 | controller | skipping: Conditional result was False
2026-02-07 00:36:35.287860 | 
2026-02-07 00:36:35.287980 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-07 00:36:35.303158 | controller | skipping: Conditional result was False
2026-02-07 00:36:35.339860 | 
2026-02-07 00:36:35.339933 | PLAY RECAP
2026-02-07 00:36:35.339976 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-07 00:36:35.339997 | 
2026-02-07 00:36:35.437004 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-07 00:36:35.437879 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-07 00:36:36.042465 | 
2026-02-07 00:36:36.042569 | PLAY [all:!appliance*]
2026-02-07 00:36:36.074529 | 
2026-02-07 00:36:36.074642 | TASK [unregister the node]
2026-02-07 00:36:36.117429 | controller | skipping: Conditional result was False
2026-02-07 00:36:36.122954 | 
2026-02-07 00:36:36.123028 | TASK [include_role : fetch-output]
2026-02-07 00:36:36.152003 | controller | ok
2026-02-07 00:36:36.170461 | 
2026-02-07 00:36:36.170525 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-07 00:36:36.214500 | controller | skipping: Conditional result was False
2026-02-07 00:36:36.220213 | 
2026-02-07 00:36:36.220278 | TASK [fetch-output : Set log path for single node]
2026-02-07 00:36:36.265959 | controller | ok
2026-02-07 00:36:36.277276 | 
2026-02-07 00:36:36.277365 | LOOP [fetch-output : Ensure local output dirs]
2026-02-07 00:36:36.656468 | controller -> localhost | ok: "/var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/logs"
2026-02-07 00:36:36.884928 | controller -> localhost | changed: "/var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/artifacts"
2026-02-07 00:36:37.087303 | controller -> localhost | changed: "/var/lib/zuul/builds/0e34c8ffa93545dd8e39d9d682243f1d/work/docs"
2026-02-07 00:36:37.100595 | 
2026-02-07 00:36:37.100716 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-07 00:36:37.722194 | controller | changed:
2026-02-07 00:36:37.722519 | controller | .d..t...... ./
2026-02-07 00:36:37.722578 | controller | cd+++++++++ controller/
2026-02-07 00:36:37.722644 | controller | changed: All items complete
2026-02-07 00:36:37.722722 | 
2026-02-07 00:36:38.190949 | controller | changed: .d..t...... ./
2026-02-07 00:36:38.631830 | controller | changed: .d..t...... ./
2026-02-07 00:36:38.657155 | 
2026-02-07 00:36:38.657313 | TASK [include_role : fetch-output-openshift]
2026-02-07 00:36:38.682868 | controller | skipping: Conditional result was False
2026-02-07 00:36:38.692705 | 
2026-02-07 00:36:38.692847 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-07 00:36:38.736457 | controller | skipping: Conditional result was False
2026-02-07 00:36:38.747563 | controller | skipping: Conditional result was False
2026-02-07 00:36:38.796755 | 
2026-02-07 00:36:38.796893 | PLAY [localhost]
2026-02-07 00:36:38.809202 | 
2026-02-07 00:36:38.809271 | TASK [Run Zuul manifest role]
2026-02-07 00:36:38.827173 | localhost | ok
2026-02-07 00:36:38.840156 | 
2026-02-07 00:36:38.840246 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-07 00:36:39.234924 | localhost | changed
2026-02-07 00:36:39.239714 | 
2026-02-07 00:36:39.239780 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-07 00:36:39.268194 | localhost | ok
2026-02-07 00:36:39.276496 | 
2026-02-07 00:36:39.276566 | TASK [Set zuul-log-path fact]
2026-02-07 00:36:39.294289 | localhost | ok
2026-02-07 00:36:39.307909 | 
2026-02-07 00:36:39.308018 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-07 00:36:39.336896 | localhost | ok
2026-02-07 00:36:39.346269 | 
2026-02-07 00:36:39.346341 | LOOP [Run upload-logs-swift role]
2026-02-07 00:36:39.383745 | localhost | Output suppressed because no_log was given
2026-02-07 00:36:39.409270 | 
2026-02-07 00:36:39.409381 | TASK [Set zuul-log-path fact]
2026-02-07 00:36:39.434035 | localhost | skipping: Conditional result was False
2026-02-07 00:36:39.438899 | 
2026-02-07 00:36:39.438964 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-07 00:36:39.850034 | localhost -> localhost | ok: Runtime: 0:00:00.008386
2026-02-07 00:36:39.855489 | 
2026-02-07 00:36:39.855567 | TASK [upload-logs-swift : Upload logs to swift]