2026-02-01 00:07:23.329963 | Job console starting...
2026-02-01 00:07:23.342630 | Updating repositories
2026-02-01 00:07:23.471735 | Preparing job workspace
2026-02-01 00:07:41.740935 | Running Ansible setup...
2026-02-01 00:07:46.656883 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-01 00:07:50.422348 | 
2026-02-01 00:07:50.424894 | PLAY [localhost]
2026-02-01 00:07:50.445579 | 
2026-02-01 00:07:50.445735 | TASK [Gathering Facts]
2026-02-01 00:07:51.670374 | localhost | ok
2026-02-01 00:07:51.684174 | 
2026-02-01 00:07:51.684339 | TASK [Setup log path fact]
2026-02-01 00:07:51.703825 | localhost | ok
2026-02-01 00:07:51.717342 | 
2026-02-01 00:07:51.719128 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-01 00:07:51.740963 | localhost | ok
2026-02-01 00:07:51.749628 | 
2026-02-01 00:07:51.749733 | TASK [emit-job-header : Print job information]
2026-02-01 00:07:51.779900 | # Job Information
2026-02-01 00:07:51.780091 | Ansible Version: 2.15.12
2026-02-01 00:07:51.780138 | Job: ansible-test-sanity-docker-devel
2026-02-01 00:07:51.780170 | Pipeline: periodic
2026-02-01 00:07:51.780199 | Executor: ze04.softwarefactory-project.io
2026-02-01 00:07:51.780226 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-01 00:07:51.780259 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/379/ansible/379e8d78406a44e981cb057ef98be05a/
2026-02-01 00:07:51.780289 | Event ID: 04be55980abd4211aa5248e6fab4a21f
2026-02-01 00:07:51.785991 | 
2026-02-01 00:07:51.786096 | LOOP [emit-job-header : Print node information]
2026-02-01 00:07:51.933501 | localhost | ok:
2026-02-01 00:07:51.933790 | localhost | # Node Information
2026-02-01 00:07:51.933824 | localhost | Inventory Hostname: controller
2026-02-01 00:07:51.933845 | localhost | Hostname: np0005604128
2026-02-01 00:07:51.933865 | localhost | Username: zuul
2026-02-01 00:07:51.933890 | localhost | Distro: Fedora 37
2026-02-01 00:07:51.933910 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-01 00:07:51.933929 | localhost | Region: ca-ymq-1
2026-02-01 00:07:51.933947 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-01 00:07:51.933964 | localhost | Product Name: OpenStack Nova
2026-02-01 00:07:51.933982 | localhost | Interface IP: 162.253.55.250
2026-02-01 00:07:51.952030 | 
2026-02-01 00:07:51.952167 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-01 00:07:52.457163 | localhost -> localhost | changed
2026-02-01 00:07:52.463269 | 
2026-02-01 00:07:52.463364 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-01 00:07:53.359567 | localhost -> localhost | changed
2026-02-01 00:07:53.381367 | 
2026-02-01 00:07:53.381455 | PLAY [all:!appliance*]
2026-02-01 00:07:53.398040 | 
2026-02-01 00:07:53.398141 | TASK [include_role : start-zuul-console]
2026-02-01 00:07:53.418414 | controller | ok
2026-02-01 00:07:53.433536 | 
2026-02-01 00:07:53.433708 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-01 00:07:53.803159 | controller | ok
2026-02-01 00:07:53.818761 | 
2026-02-01 00:07:53.818866 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-01 00:07:54.795893 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-01 00:07:54.805907 | 
2026-02-01 00:07:54.806023 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-01 00:07:55.360511 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.367021 | 
2026-02-01 00:07:55.367092 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-01 00:07:55.401465 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.407965 | 
2026-02-01 00:07:55.408038 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-01 00:07:55.432963 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.439921 | 
2026-02-01 00:07:55.440020 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-01 00:07:55.470257 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.476347 | 
2026-02-01 00:07:55.476423 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-01 00:07:55.500990 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.508388 | 
2026-02-01 00:07:55.508481 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-01 00:07:55.532901 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.544097 | 
2026-02-01 00:07:55.544198 | TASK [Disable Fedora Modular]
2026-02-01 00:07:55.801129 | controller | changed
2026-02-01 00:07:55.818965 | 
2026-02-01 00:07:55.819098 | TASK [Enable EPEL]
2026-02-01 00:07:55.852936 | controller | skipping: Conditional result was False
2026-02-01 00:07:55.859631 | 
2026-02-01 00:07:55.859804 | TASK [Register the RHEL node]
2026-02-01 00:07:56.402108 | 
2026-02-01 00:07:56.402279 | TASK [Show the subscription-manager status]
2026-02-01 00:07:57.003156 | controller | skipping: Conditional result was False
2026-02-01 00:07:57.011437 | 
2026-02-01 00:07:57.011644 | TASK [Enable EPEL on RHEL]
2026-02-01 00:07:57.063119 | controller | skipping: Conditional result was False
2026-02-01 00:07:57.071066 | 
2026-02-01 00:07:57.071164 | TASK [Install git and tox]
2026-02-01 00:09:19.787355 | controller | changed
2026-02-01 00:09:19.794352 | 
2026-02-01 00:09:19.794457 | TASK [include_role : prepare-workspace]
2026-02-01 00:09:19.825710 | controller | ok
2026-02-01 00:09:19.849640 | 
2026-02-01 00:09:19.849774 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-01 00:09:20.086149 | controller | ok
2026-02-01 00:09:20.094750 | 
2026-02-01 00:09:20.094851 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-01 00:14:50.003202 | controller | Output suppressed because no_log was given
2026-02-01 00:14:50.012836 | 
2026-02-01 00:14:50.012897 | TASK [include_role : prepare-workspace-openshift]
2026-02-01 00:14:50.038851 | controller | skipping: Conditional result was False
2026-02-01 00:14:50.064168 | 
2026-02-01 00:14:50.064267 | PLAY [all:!appliance]
2026-02-01 00:14:50.085507 | 
2026-02-01 00:14:50.085626 | TASK [Run add-build-sshkey role (RSA)]
2026-02-01 00:14:50.107215 | controller | ok
2026-02-01 00:14:50.126760 | 
2026-02-01 00:14:50.126877 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-01 00:14:50.401551 | controller -> localhost | ok
2026-02-01 00:14:50.412302 | 
2026-02-01 00:14:50.412471 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-01 00:14:50.436478 | controller | ok
2026-02-01 00:14:50.457617 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-01 00:14:50.466648 | 
2026-02-01 00:14:50.466816 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-01 00:14:50.993084 | controller -> localhost | Generating public/private rsa key pair.
2026-02-01 00:14:50.993308 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_rsa.
2026-02-01 00:14:50.993338 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_rsa.pub.
2026-02-01 00:14:50.993359 | controller -> localhost | The key fingerprint is:
2026-02-01 00:14:50.993379 | controller -> localhost | SHA256:t6SEB0rgqliuTShsy8X8XbGuzjxYlmLx4h2fFa6pjcU zuul-build-sshkey
2026-02-01 00:14:50.993398 | controller -> localhost | The key's randomart image is:
2026-02-01 00:14:50.993416 | controller -> localhost | +---[RSA 2048]----+
2026-02-01 00:14:50.993434 | controller -> localhost | |  .              |
2026-02-01 00:14:50.993453 | controller -> localhost | | . .             |
2026-02-01 00:14:50.993471 | controller -> localhost | |  . . .          |
2026-02-01 00:14:50.993488 | controller -> localhost | | . . o o   .     |
2026-02-01 00:14:50.993505 | controller -> localhost | |. . . + S.+ .    |
2026-02-01 00:14:50.993534 | controller -> localhost | |++o  + O.+o+     |
2026-02-01 00:14:50.993556 | controller -> localhost | |=oo+o B +E*      |
2026-02-01 00:14:50.993575 | controller -> localhost | |++o .o+o*=       |
2026-02-01 00:14:50.993593 | controller -> localhost | |.o.  ..O+o       |
2026-02-01 00:14:50.993614 | controller -> localhost | +----[SHA256]-----+
2026-02-01 00:14:50.993668 | controller -> localhost | ok: Runtime: 0:00:00.087651
2026-02-01 00:14:51.000008 | 
2026-02-01 00:14:51.000073 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-01 00:14:51.031244 | controller | ok
2026-02-01 00:14:51.049977 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-01 00:14:51.059725 | 
2026-02-01 00:14:51.059790 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-01 00:14:51.084382 | controller | skipping: Conditional result was False
2026-02-01 00:14:51.090469 | 
2026-02-01 00:14:51.090536 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-01 00:14:51.729106 | controller | changed
2026-02-01 00:14:51.738635 | 
2026-02-01 00:14:51.738797 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-01 00:14:51.997500 | controller | ok
2026-02-01 00:14:52.015624 | 
2026-02-01 00:14:52.015790 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-01 00:14:52.659326 | controller | changed
2026-02-01 00:14:52.670453 | 
2026-02-01 00:14:52.670547 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-01 00:14:53.291136 | controller | changed
2026-02-01 00:14:53.297392 | 
2026-02-01 00:14:53.297496 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-01 00:14:53.321986 | controller | skipping: Conditional result was False
2026-02-01 00:14:53.330981 | 
2026-02-01 00:14:53.331127 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-01 00:14:53.767996 | controller -> localhost | changed
2026-02-01 00:14:53.786124 | 
2026-02-01 00:14:53.786262 | TASK [add-build-sshkey : Add back temp key]
2026-02-01 00:14:54.129298 | controller -> localhost | Identity added: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_rsa (zuul-build-sshkey)
2026-02-01 00:14:54.129569 | controller -> localhost | ok: Runtime: 0:00:00.016445
2026-02-01 00:14:54.137108 | 
2026-02-01 00:14:54.137181 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-01 00:14:54.492886 | controller | ok
2026-02-01 00:14:54.504719 | 
2026-02-01 00:14:54.504871 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-01 00:14:54.532503 | controller | skipping: Conditional result was False
2026-02-01 00:14:54.553575 | 
2026-02-01 00:14:54.553768 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-01 00:14:54.587241 | controller | ok
2026-02-01 00:14:54.605143 | 
2026-02-01 00:14:54.605295 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-01 00:14:54.887201 | controller -> localhost | ok
2026-02-01 00:14:54.894452 | 
2026-02-01 00:14:54.894557 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-01 00:14:54.928479 | controller | ok
2026-02-01 00:14:54.940908 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-01 00:14:54.947365 | 
2026-02-01 00:14:54.947447 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-01 00:14:55.279774 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-01 00:14:55.280053 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_ecdsa.
2026-02-01 00:14:55.280095 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_ecdsa.pub.
2026-02-01 00:14:55.280142 | controller -> localhost | The key fingerprint is:
2026-02-01 00:14:55.280172 | controller -> localhost | SHA256:+G5LEyv9a4c9akVzhSlR9ViysQ00qfUBVeaA+VtdQHg zuul-build-sshkey
2026-02-01 00:14:55.280200 | controller -> localhost | The key's randomart image is:
2026-02-01 00:14:55.280229 | controller -> localhost | +---[ECDSA 521]---+
2026-02-01 00:14:55.280256 | controller -> localhost | |            .X&B*|
2026-02-01 00:14:55.280282 | controller -> localhost | |            = E/+|
2026-02-01 00:14:55.280308 | controller -> localhost | |             *+oB|
2026-02-01 00:14:55.280334 | controller -> localhost | |       .    + o +|
2026-02-01 00:14:55.280360 | controller -> localhost | |      . S  . o o |
2026-02-01 00:14:55.280385 | controller -> localhost | |       o o  . .  |
2026-02-01 00:14:55.280410 | controller -> localhost | |      . *  +     |
2026-02-01 00:14:55.280435 | controller -> localhost | |       +.o+ +    |
2026-02-01 00:14:55.280460 | controller -> localhost | |       .o+++ .   |
2026-02-01 00:14:55.280485 | controller -> localhost | +----[SHA256]-----+
2026-02-01 00:14:55.280551 | controller -> localhost | ok: Runtime: 0:00:00.010126
2026-02-01 00:14:55.293107 | 
2026-02-01 00:14:55.293336 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-01 00:14:55.329324 | controller | ok
2026-02-01 00:14:55.338088 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-01 00:14:55.349573 | 
2026-02-01 00:14:55.349739 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-01 00:14:55.375326 | controller | skipping: Conditional result was False
2026-02-01 00:14:55.382878 | 
2026-02-01 00:14:55.383011 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-01 00:14:55.651593 | controller | changed
2026-02-01 00:14:55.661629 | 
2026-02-01 00:14:55.661803 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-01 00:14:55.898982 | controller | ok
2026-02-01 00:14:55.905663 | 
2026-02-01 00:14:55.905767 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-01 00:14:56.610905 | controller | changed
2026-02-01 00:14:56.616485 | 
2026-02-01 00:14:56.616551 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-01 00:14:57.217598 | controller | changed
2026-02-01 00:14:57.233476 | 
2026-02-01 00:14:57.233977 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-01 00:14:57.264155 | controller | skipping: Conditional result was False
2026-02-01 00:14:57.278511 | 
2026-02-01 00:14:57.278715 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-01 00:14:57.531349 | controller -> localhost | changed
2026-02-01 00:14:57.545078 | 
2026-02-01 00:14:57.545220 | TASK [add-build-sshkey : Add back temp key]
2026-02-01 00:14:57.836449 | controller -> localhost | Identity added: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/379e8d78406a44e981cb057ef98be05a_id_ecdsa (zuul-build-sshkey)
2026-02-01 00:14:57.836778 | controller -> localhost | ok: Runtime: 0:00:00.008593
2026-02-01 00:14:57.843784 | 
2026-02-01 00:14:57.843861 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-01 00:14:58.048254 | controller | ok
2026-02-01 00:14:58.055946 | 
2026-02-01 00:14:58.056047 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-01 00:14:58.080557 | controller | skipping: Conditional result was False
2026-02-01 00:14:58.093077 | 
2026-02-01 00:14:58.093217 | TASK [include_role : remove-zuul-sshkey]
2026-02-01 00:14:58.108244 | controller | skipping: Conditional result was False
2026-02-01 00:14:58.115584 | 
2026-02-01 00:14:58.115666 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-01 00:14:58.349923 | controller | ok: "logs"
2026-02-01 00:14:58.350192 | controller | ok: All items complete
2026-02-01 00:14:58.350219 | 
2026-02-01 00:14:58.579511 | controller | ok: "artifacts"
2026-02-01 00:14:58.775594 | controller | ok: "docs"
2026-02-01 00:14:58.799343 | 
2026-02-01 00:14:58.799523 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-01 00:14:59.051159 | controller | changed: "logs"
2026-02-01 00:14:59.222626 | controller | changed: "artifacts"
2026-02-01 00:14:59.408661 | controller | changed: "docs"
2026-02-01 00:14:59.448407 | 
2026-02-01 00:14:59.448515 | PLAY RECAP
2026-02-01 00:14:59.448559 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-01 00:14:59.448584 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-01 00:14:59.448602 | 
2026-02-01 00:14:59.589434 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-01 00:14:59.590631 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-01 00:15:00.238726 | 
2026-02-01 00:15:00.238858 | PLAY [all]
2026-02-01 00:15:00.264871 | 
2026-02-01 00:15:00.265061 | TASK [Install binary dependencies]
2026-02-01 00:15:00.329555 | controller | ok
2026-02-01 00:15:00.360640 | 
2026-02-01 00:15:00.360814 | TASK [bindep : Include find tasks]
2026-02-01 00:15:00.391177 | controller | ok
2026-02-01 00:15:00.401405 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-01 00:15:00.408662 | 
2026-02-01 00:15:00.408798 | TASK [bindep : Look for bindep.txt]
2026-02-01 00:15:00.965140 | controller | ok
2026-02-01 00:15:00.971634 | 
2026-02-01 00:15:00.971787 | TASK [bindep : Define bindep_file fact]
2026-02-01 00:15:00.996647 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.003757 | 
2026-02-01 00:15:01.003861 | TASK [bindep : Look for other-requirements.txt]
2026-02-01 00:15:01.204798 | controller | ok
2026-02-01 00:15:01.213771 | 
2026-02-01 00:15:01.213906 | TASK [bindep : Define bindep_file fact]
2026-02-01 00:15:01.250251 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.267058 | 
2026-02-01 00:15:01.267304 | TASK [bindep : Look for bindep fallback file]
2026-02-01 00:15:01.304982 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.315481 | 
2026-02-01 00:15:01.315644 | TASK [bindep : Define bindep_file fact]
2026-02-01 00:15:01.341021 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.349097 | 
2026-02-01 00:15:01.349251 | TASK [bindep : Include bindep tasks]
2026-02-01 00:15:01.373726 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.381058 | 
2026-02-01 00:15:01.381169 | TASK [bindep : Include install tasks]
2026-02-01 00:15:01.405635 | controller | skipping: Conditional result was False
2026-02-01 00:15:01.417704 | 
2026-02-01 00:15:01.417949 | LOOP [bindep : Include package tasks]
2026-02-01 00:15:01.487310 | 
2026-02-01 00:15:01.487492 | TASK [Run test-setup role]
2026-02-01 00:15:01.509791 | controller | ok
2026-02-01 00:15:01.530971 | 
2026-02-01 00:15:01.531121 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-01 00:15:01.739745 | controller | ok
2026-02-01 00:15:01.747022 | 
2026-02-01 00:15:01.747129 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-01 00:15:02.291564 | controller | skipping: Conditional result was False
2026-02-01 00:15:02.331190 | 
2026-02-01 00:15:02.331436 | PLAY RECAP
2026-02-01 00:15:02.331568 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-01 00:15:02.331647 | 
2026-02-01 00:15:02.489754 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-01 00:15:02.491645 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-01 00:15:03.115474 | 
2026-02-01 00:15:03.115613 | PLAY [controller]
2026-02-01 00:15:03.136136 | 
2026-02-01 00:15:03.136243 | TASK [Create the /root directory]
2026-02-01 00:15:03.731031 | controller | ok
2026-02-01 00:15:03.737888 | 
2026-02-01 00:15:03.737987 | TASK [Install glibc-langpack-en]
2026-02-01 00:15:07.691657 | controller | ok: Nothing to do
2026-02-01 00:15:07.704175 | 
2026-02-01 00:15:07.704313 | TASK [Ensure controller directory exists]
2026-02-01 00:15:07.932052 | controller | changed
2026-02-01 00:15:07.939104 | 
2026-02-01 00:15:07.939205 | TASK [Install container runtime]
2026-02-01 00:15:08.001855 | controller | ok
2026-02-01 00:15:08.045038 | 
2026-02-01 00:15:08.045192 | LOOP [ensure-podman : Find distribution installation]
2026-02-01 00:15:08.080935 | controller | ok: "/var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-01 00:15:08.093420 | controller | included: /var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-01 00:15:08.110864 | 
2026-02-01 00:15:08.111034 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-01 00:16:13.823568 | controller | changed
2026-02-01 00:16:13.839092 | 
2026-02-01 00:16:13.839394 | TASK [ensure-podman : Fetch podman version]
2026-02-01 00:16:14.442742 | controller | Client:       Podman Engine
2026-02-01 00:16:14.471124 | controller | Version:      4.6.2
2026-02-01 00:16:14.471150 | controller | API Version:  4.6.2
2026-02-01 00:16:14.471158 | controller | Go Version:   go1.19.12
2026-02-01 00:16:14.471175 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-01 00:16:14.471182 | controller | OS/Arch:      linux/amd64
2026-02-01 00:16:14.894394 | controller | ok: Runtime: 0:00:00.226611
2026-02-01 00:16:14.902743 | 
2026-02-01 00:16:14.902847 | TASK [ensure-podman : Print podman version installed]
2026-02-01 00:16:14.934721 | Podman version: Client:       Podman Engine
2026-02-01 00:16:14.934899 | Version:      4.6.2
2026-02-01 00:16:14.934929 | API Version:  4.6.2
2026-02-01 00:16:14.934950 | Go Version:   go1.19.12
2026-02-01 00:16:14.934968 | Built:        Mon Aug 28 19:38:31 2023
2026-02-01 00:16:14.934986 | OS/Arch:      linux/amd64
2026-02-01 00:16:14.941246 | 
2026-02-01 00:16:14.941356 | TASK [ensure-podman : Validate podman engine]
2026-02-01 00:16:15.475758 | controller | skipping: Conditional result was False
2026-02-01 00:16:15.484359 | 
2026-02-01 00:16:15.484506 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-01 00:16:15.499323 | controller | skipping: Conditional result was False
2026-02-01 00:16:15.517926 | 
2026-02-01 00:16:15.518075 | TASK [Ensure python3.8 is present]
2026-02-01 00:16:15.532548 | controller | skipping: Conditional result was False
2026-02-01 00:16:15.543261 | 
2026-02-01 00:16:15.543414 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-01 00:16:15.567491 | controller | ok
2026-02-01 00:16:15.595156 | 
2026-02-01 00:16:15.595431 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-01 00:16:16.958463 | controller | ok: Nothing to do
2026-02-01 00:16:16.968446 | 
2026-02-01 00:16:16.968551 | TASK [our-ensure-python : Also install python3-devel]
2026-02-01 00:16:27.114386 | controller | changed
2026-02-01 00:16:27.131960 | 
2026-02-01 00:16:27.132118 | TASK [Run ensure-virtualenv role]
2026-02-01 00:16:27.157205 | controller | ok
2026-02-01 00:16:27.185888 | 
2026-02-01 00:16:27.186008 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-01 00:16:27.447076 | controller | /usr/bin/virtualenv
2026-02-01 00:16:27.754126 | controller | ok: Runtime: 0:00:00.003648
2026-02-01 00:16:27.770078 | 
2026-02-01 00:16:27.770244 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-01 00:16:27.810126 | controller | skipping: Conditional result was False
2026-02-01 00:16:27.810622 | controller | ok: All items complete
2026-02-01 00:16:27.810711 | 
2026-02-01 00:16:27.845127 | 
2026-02-01 00:16:27.845380 | TASK [Find the full path of the Python interpreter]
2026-02-01 00:16:28.071282 | controller | /usr/bin/python3
2026-02-01 00:16:28.395760 | controller | ok
2026-02-01 00:16:28.402662 | 
2026-02-01 00:16:28.402786 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-01 00:16:29.393703 | controller | created virtual environment CPython3.11.0.final.0-64 in 561ms
2026-02-01 00:16:29.411193 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-01 00:16:29.411207 | 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-01 00:16:29.411215 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-01 00:16:29.411228 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-01 00:16:29.449549 | controller | changed
2026-02-01 00:16:29.457989 | 
2026-02-01 00:16:29.458069 | TASK [Set selinux package]
2026-02-01 00:16:29.480429 | controller | ok
2026-02-01 00:16:29.487874 | 
2026-02-01 00:16:29.488038 | TASK [Set selinux package (Fedora)]
2026-02-01 00:16:29.523654 | controller | ok
2026-02-01 00:16:29.533894 | 
2026-02-01 00:16:29.534046 | TASK [Install selinux into virtualenv]
2026-02-01 00:16:54.986332 | controller | Collecting selinux-please-lie-to-me
2026-02-01 00:17:07.247411 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-01 00:17:07.553040 | controller | Collecting setuptools<50.0.0
2026-02-01 00:17:07.558227 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-01 00:17:07.604252 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.2 MB/s eta 0:00:00
2026-02-01 00:17:07.684854 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-01 00:17:07.685102 | controller |   Attempting uninstall: setuptools
2026-02-01 00:17:07.687607 | controller |     Found existing installation: setuptools 62.6.0
2026-02-01 00:17:07.746932 | controller |     Uninstalling setuptools-62.6.0:
2026-02-01 00:17:07.754968 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-01 00:17:08.100952 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-01 00:17:19.642381 | controller |
2026-02-01 00:17:19.724841 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-01 00:17:19.724883 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-01 00:17:20.091176 | controller | ok: Runtime: 0:00:49.988357
2026-02-01 00:17:20.103267 | 
2026-02-01 00:17:20.103406 | TASK [Install pytest-forked into virtualenv]
2026-02-01 00:17:29.828207 | controller | Collecting pytest-forked
2026-02-01 00:17:42.183277 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-01 00:17:42.222887 | controller | Collecting py
2026-02-01 00:17:42.227967 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-01 00:17:42.245323 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.6 MB/s eta 0:00:00
2026-02-01 00:17:42.354478 | controller | Collecting pytest>=3.10
2026-02-01 00:17:42.358810 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-01 00:17:42.374922 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.8 MB/s eta 0:00:00
2026-02-01 00:17:42.411855 | controller | Collecting iniconfig>=1.0.1
2026-02-01 00:17:42.415574 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-01 00:17:42.461108 | controller | Collecting packaging>=22
2026-02-01 00:17:42.464508 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-01 00:17:42.471504 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 20.0 MB/s eta 0:00:00
2026-02-01 00:17:42.503850 | controller | Collecting pluggy<2,>=1.5
2026-02-01 00:17:42.506917 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-01 00:17:42.560351 | controller | Collecting pygments>=2.7.2
2026-02-01 00:17:42.563761 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-01 00:17:42.584919 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 65.8 MB/s eta 0:00:00
2026-02-01 00:17:42.656807 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-01 00:17:43.712726 | 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-01 00:17:43.721816 | controller |
2026-02-01 00:17:43.795056 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-01 00:17:43.795104 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-01 00:17:44.163937 | controller | ok: Runtime: 0:00:23.462153
2026-02-01 00:17:44.172185 | 
2026-02-01 00:17:44.172371 | TASK [Update pip]
2026-02-01 00:17:44.726932 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-01 00:17:54.566824 | controller | Collecting pip
2026-02-01 00:18:06.760175 | controller |   Downloading pip-26.0-py3-none-any.whl (1.8 MB)
2026-02-01 00:18:06.813808 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 37.3 MB/s eta 0:00:00
2026-02-01 00:18:06.880873 | controller | Installing collected packages: pip
2026-02-01 00:18:06.881050 | controller |   Attempting uninstall: pip
2026-02-01 00:18:06.883230 | controller |     Found existing installation: pip 22.2.2
2026-02-01 00:18:07.021135 | controller |     Uninstalling pip-22.2.2:
2026-02-01 00:18:07.036343 | controller |       Successfully uninstalled pip-22.2.2
2026-02-01 00:18:07.864748 | controller | Successfully installed pip-26.0
2026-02-01 00:18:08.249940 | controller | ok: Runtime: 0:00:23.514284
2026-02-01 00:18:08.259826 | 
2026-02-01 00:18:08.260008 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-01 00:18:08.470527 | controller | changed
2026-02-01 00:18:08.477275 | 
2026-02-01 00:18:08.477664 | TASK [Install ansible into virtualenv]
2026-02-01 00:18:08.988256 | controller | Processing ./src/github.com/ansible/ansible
2026-02-01 00:18:08.990592 | controller |   Installing build dependencies: started
2026-02-01 00:18:31.671502 | controller |   Installing build dependencies: finished with status 'done'
2026-02-01 00:18:31.672191 | controller |   Getting requirements to build wheel: started
2026-02-01 00:18:32.430089 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-01 00:18:32.431035 | controller |   Preparing metadata (pyproject.toml): started
2026-02-01 00:18:32.900063 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-01 00:18:32.904724 | 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-01 00:18:32.908287 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-01 00:18:33.035042 | controller | ERROR
2026-02-01 00:18:33.035192 | controller | {
2026-02-01 00:18:33.035220 | controller |   "delta": "0:00:24.270901",
2026-02-01 00:18:33.035239 | controller |   "end": "2026-02-01 00:18:32.970642",
2026-02-01 00:18:33.035256 | controller |   "msg": "non-zero return code",
2026-02-01 00:18:33.035283 | controller |   "rc": 1,
2026-02-01 00:18:33.035300 | controller |   "start": "2026-02-01 00:18:08.699741"
2026-02-01 00:18:33.035316 | controller | }
failure
2026-02-01 00:18:33.036935 | 
2026-02-01 00:18:33.036983 | PLAY RECAP
2026-02-01 00:18:33.037028 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-01 00:18:33.037052 | 
2026-02-01 00:18:33.228206 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-01 00:18:33.229313 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-01 00:18:33.946387 | 
2026-02-01 00:18:33.946596 | PLAY [all]
2026-02-01 00:18:33.975485 | 
2026-02-01 00:18:33.975747 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-01 00:18:34.413176 | controller | changed: non-zero return code
2026-02-01 00:18:34.422090 | 
2026-02-01 00:18:34.422202 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-01 00:18:34.447793 | controller | skipping: Conditional result was False
2026-02-01 00:18:34.460841 | 
2026-02-01 00:18:34.461087 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-01 00:18:34.499259 | 
2026-02-01 00:18:34.499487 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-01 00:18:34.546057 | 
2026-02-01 00:18:34.546322 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-01 00:18:34.572541 | controller | skipping: Conditional result was False
2026-02-01 00:18:34.587496 | 
2026-02-01 00:18:34.587733 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-01 00:18:34.624955 | 
2026-02-01 00:18:34.625196 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-01 00:18:34.651894 | controller | skipping: Conditional result was False
2026-02-01 00:18:34.664434 | 
2026-02-01 00:18:34.664612 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-01 00:18:34.683877 | controller | skipping: Conditional result was False
2026-02-01 00:18:34.692865 | 
2026-02-01 00:18:34.693038 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-01 00:18:34.710017 | controller | skipping: Conditional result was False
2026-02-01 00:18:34.751593 | 
2026-02-01 00:18:34.751748 | PLAY RECAP
2026-02-01 00:18:34.751798 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-01 00:18:34.751819 | 
2026-02-01 00:18:34.903283 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-01 00:18:34.904331 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-01 00:18:35.660385 | 
2026-02-01 00:18:35.660537 | PLAY [all:!appliance*]
2026-02-01 00:18:35.691182 | 
2026-02-01 00:18:35.691326 | TASK [unregister the node]
2026-02-01 00:18:36.230829 | controller | skipping: Conditional result was False
2026-02-01 00:18:36.247798 | 
2026-02-01 00:18:36.248111 | TASK [include_role : fetch-output]
2026-02-01 00:18:36.302055 | controller | ok
2026-02-01 00:18:36.326576 | 
2026-02-01 00:18:36.326753 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-01 00:18:36.392831 | controller | skipping: Conditional result was False
2026-02-01 00:18:36.411117 | 
2026-02-01 00:18:36.411404 | TASK [fetch-output : Set log path for single node]
2026-02-01 00:18:36.462440 | controller | ok
2026-02-01 00:18:36.472275 | 
2026-02-01 00:18:36.472451 | LOOP [fetch-output : Ensure local output dirs]
2026-02-01 00:18:36.939568 | controller -> localhost | ok: "/var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/logs"
2026-02-01 00:18:37.210171 | controller -> localhost | changed: "/var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/artifacts"
2026-02-01 00:18:37.471645 | controller -> localhost | changed: "/var/lib/zuul/builds/379e8d78406a44e981cb057ef98be05a/work/docs"
2026-02-01 00:18:37.491015 | 
2026-02-01 00:18:37.491123 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-01 00:18:38.199127 | controller | changed:
2026-02-01 00:18:38.199392 | controller | .d..t...... ./
2026-02-01 00:18:38.199429 | controller | cd+++++++++ controller/
2026-02-01 00:18:38.199466 | controller | changed: All items complete
2026-02-01 00:18:38.199486 | 
2026-02-01 00:18:38.669956 | controller | changed: .d..t...... ./
2026-02-01 00:18:39.205081 | controller | changed: .d..t...... ./
2026-02-01 00:18:39.224600 | 
2026-02-01 00:18:39.224716 | TASK [include_role : fetch-output-openshift]
2026-02-01 00:18:39.248928 | controller | skipping: Conditional result was False
2026-02-01 00:18:39.256586 | 
2026-02-01 00:18:39.256710 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-01 00:18:39.313213 | controller | skipping: Conditional result was False
2026-02-01 00:18:39.329392 | controller | skipping: Conditional result was False
2026-02-01 00:18:39.381081 | 
2026-02-01 00:18:39.381227 | PLAY [localhost]
2026-02-01 00:18:39.393731 | 
2026-02-01 00:18:39.393828 | TASK [Run Zuul manifest role]
2026-02-01 00:18:39.413536 | localhost | ok
2026-02-01 00:18:39.431760 | 
2026-02-01 00:18:39.431921 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-01 00:18:39.808525 | localhost | changed
2026-02-01 00:18:39.823183 | 
2026-02-01 00:18:39.823340 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-01 00:18:39.865364 | localhost | ok
2026-02-01 00:18:39.879891 | 
2026-02-01 00:18:39.880471 | TASK [Set zuul-log-path fact]
2026-02-01 00:18:39.908223 | localhost | ok
2026-02-01 00:18:39.933796 | 
2026-02-01 00:18:39.933964 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-01 00:18:39.974503 | localhost | ok
2026-02-01 00:18:39.982865 | 
2026-02-01 00:18:39.982928 | LOOP [Run upload-logs-swift role]
2026-02-01 00:18:40.030245 | localhost | Output suppressed because no_log was given
2026-02-01 00:18:40.067334 | 
2026-02-01 00:18:40.067510 | TASK [Set zuul-log-path fact]
2026-02-01 00:18:40.104950 | localhost | skipping: Conditional result was False
2026-02-01 00:18:40.112822 | 
2026-02-01 00:18:40.112946 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-01 00:18:40.626521 | localhost -> localhost | ok: Runtime: 0:00:00.010219
2026-02-01 00:18:40.700900 | 
2026-02-01 00:18:40.701203 | TASK [upload-logs-swift : Upload logs to swift]