2025-10-06 00:06:43.754080 | Job console starting...
2025-10-06 00:06:43.764964 | Updating repositories
2025-10-06 00:06:43.883268 | Preparing job workspace
2025-10-06 00:06:48.218935 | Running Ansible setup...
2025-10-06 00:06:53.185647 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-06 00:06:53.919128 | 
2025-10-06 00:06:53.919259 | PLAY [localhost]
2025-10-06 00:06:53.928618 | 
2025-10-06 00:06:53.928725 | TASK [Gathering Facts]
2025-10-06 00:06:55.025443 | localhost | ok
2025-10-06 00:06:55.053387 | 
2025-10-06 00:06:55.053581 | TASK [Setup log path fact]
2025-10-06 00:06:55.074190 | localhost | ok
2025-10-06 00:06:55.092106 | 
2025-10-06 00:06:55.092209 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-06 00:06:55.122818 | localhost | ok
2025-10-06 00:06:55.134148 | 
2025-10-06 00:06:55.134254 | TASK [emit-job-header : Print job information]
2025-10-06 00:06:55.165453 | # Job Information
2025-10-06 00:06:55.165620 | Ansible Version: 2.15.12
2025-10-06 00:06:55.165667 | Job: ansible-test-sanity-docker-stable-2.12
2025-10-06 00:06:55.165724 | Pipeline: periodic
2025-10-06 00:06:55.165755 | Executor: ze04.softwarefactory-project.io
2025-10-06 00:06:55.165785 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-06 00:06:55.165816 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b2e/ansible/b2e3c6fc1cfa430785291cc2ad72f074/
2025-10-06 00:06:55.165844 | Event ID: 9d310e2ddb83445ab53d82797698fe1c
2025-10-06 00:06:55.171460 | 
2025-10-06 00:06:55.171555 | LOOP [emit-job-header : Print node information]
2025-10-06 00:06:55.293105 | localhost | ok:
2025-10-06 00:06:55.293357 | localhost | # Node Information
2025-10-06 00:06:55.293392 | localhost | Inventory Hostname: controller
2025-10-06 00:06:55.293420 | localhost | Hostname: np0005471451
2025-10-06 00:06:55.293443 | localhost | Username: zuul
2025-10-06 00:06:55.293469 | localhost | Distro: Fedora 37
2025-10-06 00:06:55.293495 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-10-06 00:06:55.293519 | localhost | Region: ca-ymq-1
2025-10-06 00:06:55.293540 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-06 00:06:55.293562 | localhost | Product Name: OpenStack Nova
2025-10-06 00:06:55.293587 | localhost | Interface IP: 162.253.55.221
2025-10-06 00:06:55.318719 | 
2025-10-06 00:06:55.318936 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-06 00:06:55.709016 | localhost -> localhost | changed
2025-10-06 00:06:55.743563 | 
2025-10-06 00:06:55.743830 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-06 00:06:56.638708 | localhost -> localhost | changed
2025-10-06 00:06:56.671033 | 
2025-10-06 00:06:56.671134 | PLAY [all:!appliance*]
2025-10-06 00:06:56.697888 | 
2025-10-06 00:06:56.698109 | TASK [include_role : start-zuul-console]
2025-10-06 00:06:56.720475 | controller | ok
2025-10-06 00:06:56.735663 | 
2025-10-06 00:06:56.735788 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-06 00:06:57.114161 | controller | ok
2025-10-06 00:06:57.135526 | 
2025-10-06 00:06:57.135644 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-06 00:06:58.451498 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-06 00:06:58.461657 | 
2025-10-06 00:06:58.461847 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-06 00:06:59.016943 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.027479 | 
2025-10-06 00:06:59.027647 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-06 00:06:59.057409 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.075328 | 
2025-10-06 00:06:59.075524 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-06 00:06:59.106092 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.123634 | 
2025-10-06 00:06:59.123892 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-06 00:06:59.152641 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.168057 | 
2025-10-06 00:06:59.168348 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-06 00:06:59.198894 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.209514 | 
2025-10-06 00:06:59.209635 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-06 00:06:59.245242 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.260290 | 
2025-10-06 00:06:59.260380 | TASK [Disable Fedora Modular]
2025-10-06 00:06:59.545456 | controller | changed
2025-10-06 00:06:59.551222 | 
2025-10-06 00:06:59.551284 | TASK [Enable EPEL]
2025-10-06 00:06:59.575730 | controller | skipping: Conditional result was False
2025-10-06 00:06:59.581922 | 
2025-10-06 00:06:59.581986 | TASK [Register the RHEL node]
2025-10-06 00:07:00.124932 | 
2025-10-06 00:07:00.125193 | TASK [Show the subscription-manager status]
2025-10-06 00:07:00.721876 | controller | skipping: Conditional result was False
2025-10-06 00:07:00.731733 | 
2025-10-06 00:07:00.731863 | TASK [Enable EPEL on RHEL]
2025-10-06 00:07:01.278223 | controller | skipping: Conditional result was False
2025-10-06 00:07:01.284692 | 
2025-10-06 00:07:01.284796 | TASK [Install git and tox]
2025-10-06 00:08:41.599113 | controller | changed
2025-10-06 00:08:41.617201 | 
2025-10-06 00:08:41.617336 | TASK [include_role : prepare-workspace]
2025-10-06 00:08:41.651101 | controller | ok
2025-10-06 00:08:41.674470 | 
2025-10-06 00:08:41.674621 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-06 00:08:41.919572 | controller | ok
2025-10-06 00:08:41.932210 | 
2025-10-06 00:08:41.932363 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-06 00:14:01.294731 | controller | Output suppressed because no_log was given
2025-10-06 00:14:01.305711 | 
2025-10-06 00:14:01.305785 | TASK [include_role : prepare-workspace-openshift]
2025-10-06 00:14:01.330529 | controller | skipping: Conditional result was False
2025-10-06 00:14:01.357520 | 
2025-10-06 00:14:01.357708 | PLAY [all:!appliance]
2025-10-06 00:14:01.376978 | 
2025-10-06 00:14:01.377079 | TASK [Run add-build-sshkey role (RSA)]
2025-10-06 00:14:01.409080 | controller | ok
2025-10-06 00:14:01.428330 | 
2025-10-06 00:14:01.428509 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-06 00:14:01.701749 | controller -> localhost | ok
2025-10-06 00:14:01.715897 | 
2025-10-06 00:14:01.716046 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-06 00:14:01.766622 | controller | ok
2025-10-06 00:14:01.799927 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-06 00:14:01.812213 | 
2025-10-06 00:14:01.812316 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-06 00:14:02.327649 | controller -> localhost | Generating public/private rsa key pair.
2025-10-06 00:14:02.327979 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_rsa.
2025-10-06 00:14:02.328014 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_rsa.pub.
2025-10-06 00:14:02.328037 | controller -> localhost | The key fingerprint is:
2025-10-06 00:14:02.328065 | controller -> localhost | SHA256:S3GUN7pwchz+YOPwsai+HPwhRaMcUW5D7YlPVepPR90 zuul-build-sshkey
2025-10-06 00:14:02.328097 | controller -> localhost | The key's randomart image is:
2025-10-06 00:14:02.328126 | controller -> localhost | +---[RSA 2048]----+
2025-10-06 00:14:02.328151 | controller -> localhost | |      ..o... ..  |
2025-10-06 00:14:02.328176 | controller -> localhost | |       + .+ +.  o|
2025-10-06 00:14:02.328199 | controller -> localhost | |      . B=.*..  E|
2025-10-06 00:14:02.328225 | controller -> localhost | |     . ===#.   . |
2025-10-06 00:14:02.328251 | controller -> localhost | |      o S& B. . .|
2025-10-06 00:14:02.328288 | controller -> localhost | |     . o..* .o . |
2025-10-06 00:14:02.328329 | controller -> localhost | |      +.o     .  |
2025-10-06 00:14:02.328355 | controller -> localhost | |     ..+ .       |
2025-10-06 00:14:02.328375 | controller -> localhost | |     .+..        |
2025-10-06 00:14:02.328395 | controller -> localhost | +----[SHA256]-----+
2025-10-06 00:14:02.328467 | controller -> localhost | ok: Runtime: 0:00:00.093637
2025-10-06 00:14:02.338247 | 
2025-10-06 00:14:02.338334 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-06 00:14:02.375193 | controller | ok
2025-10-06 00:14:02.386825 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-06 00:14:02.396879 | 
2025-10-06 00:14:02.396997 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-06 00:14:02.423002 | controller | skipping: Conditional result was False
2025-10-06 00:14:02.430795 | 
2025-10-06 00:14:02.430879 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-06 00:14:03.126990 | controller | changed
2025-10-06 00:14:03.132794 | 
2025-10-06 00:14:03.132877 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-06 00:14:03.406508 | controller | ok
2025-10-06 00:14:03.424253 | 
2025-10-06 00:14:03.424510 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-06 00:14:04.134981 | controller | changed
2025-10-06 00:14:04.142035 | 
2025-10-06 00:14:04.142170 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-06 00:14:04.786102 | controller | changed
2025-10-06 00:14:04.801302 | 
2025-10-06 00:14:04.801522 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-06 00:14:04.829404 | controller | skipping: Conditional result was False
2025-10-06 00:14:04.846938 | 
2025-10-06 00:14:04.847179 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-06 00:14:05.336849 | controller -> localhost | changed
2025-10-06 00:14:05.354003 | 
2025-10-06 00:14:05.354144 | TASK [add-build-sshkey : Add back temp key]
2025-10-06 00:14:05.691009 | controller -> localhost | Identity added: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_rsa (zuul-build-sshkey)
2025-10-06 00:14:05.691407 | controller -> localhost | ok: Runtime: 0:00:00.009719
2025-10-06 00:14:05.700865 | 
2025-10-06 00:14:05.700965 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-06 00:14:06.101106 | controller | ok
2025-10-06 00:14:06.107370 | 
2025-10-06 00:14:06.107467 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-06 00:14:06.154560 | controller | skipping: Conditional result was False
2025-10-06 00:14:06.169160 | 
2025-10-06 00:14:06.169258 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-06 00:14:06.202849 | controller | ok
2025-10-06 00:14:06.220196 | 
2025-10-06 00:14:06.220304 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-06 00:14:06.545523 | controller -> localhost | ok
2025-10-06 00:14:06.554623 | 
2025-10-06 00:14:06.554791 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-06 00:14:06.590878 | controller | ok
2025-10-06 00:14:06.604401 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-06 00:14:06.616607 | 
2025-10-06 00:14:06.616900 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-06 00:14:06.922833 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-06 00:14:06.923061 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_ecdsa.
2025-10-06 00:14:06.923090 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_ecdsa.pub.
2025-10-06 00:14:06.923121 | controller -> localhost | The key fingerprint is:
2025-10-06 00:14:06.923141 | controller -> localhost | SHA256:w0SeGuN3ovzEGkyC2piqZyfaAjjIPSgh8MrPXOubgzY zuul-build-sshkey
2025-10-06 00:14:06.923161 | controller -> localhost | The key's randomart image is:
2025-10-06 00:14:06.923180 | controller -> localhost | +---[ECDSA 521]---+
2025-10-06 00:14:06.923198 | controller -> localhost | |        .        |
2025-10-06 00:14:06.923215 | controller -> localhost | |.      o .       |
2025-10-06 00:14:06.923233 | controller -> localhost | |..    o +        |
2025-10-06 00:14:06.923250 | controller -> localhost | |o .. . *         |
2025-10-06 00:14:06.923267 | controller -> localhost | |*o+ . + S .      |
2025-10-06 00:14:06.923285 | controller -> localhost | |BO o * + +       |
2025-10-06 00:14:06.923302 | controller -> localhost | |*.= + * o        |
2025-10-06 00:14:06.923319 | controller -> localhost | |o.+E.o.=         |
2025-10-06 00:14:06.923335 | controller -> localhost | |==ooo++ .        |
2025-10-06 00:14:06.923352 | controller -> localhost | +----[SHA256]-----+
2025-10-06 00:14:06.923405 | controller -> localhost | ok: Runtime: 0:00:00.008961
2025-10-06 00:14:06.931659 | 
2025-10-06 00:14:06.931753 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-06 00:14:06.963764 | controller | ok
2025-10-06 00:14:06.973223 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-06 00:14:06.982342 | 
2025-10-06 00:14:06.982418 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-06 00:14:07.007364 | controller | skipping: Conditional result was False
2025-10-06 00:14:07.015300 | 
2025-10-06 00:14:07.015416 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-06 00:14:07.314219 | controller | changed
2025-10-06 00:14:07.322663 | 
2025-10-06 00:14:07.322821 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-06 00:14:07.594773 | controller | ok
2025-10-06 00:14:07.614026 | 
2025-10-06 00:14:07.614396 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-06 00:14:08.294871 | controller | changed
2025-10-06 00:14:08.307070 | 
2025-10-06 00:14:08.307176 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-06 00:14:09.085482 | controller | changed
2025-10-06 00:14:09.142253 | 
2025-10-06 00:14:09.142414 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-06 00:14:09.177837 | controller | skipping: Conditional result was False
2025-10-06 00:14:09.184670 | 
2025-10-06 00:14:09.184780 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-06 00:14:09.456117 | controller -> localhost | changed
2025-10-06 00:14:09.471875 | 
2025-10-06 00:14:09.472269 | TASK [add-build-sshkey : Add back temp key]
2025-10-06 00:14:09.784968 | controller -> localhost | Identity added: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/b2e3c6fc1cfa430785291cc2ad72f074_id_ecdsa (zuul-build-sshkey)
2025-10-06 00:14:09.785274 | controller -> localhost | ok: Runtime: 0:00:00.009390
2025-10-06 00:14:09.793069 | 
2025-10-06 00:14:09.793139 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-06 00:14:10.012892 | controller | ok
2025-10-06 00:14:10.019220 | 
2025-10-06 00:14:10.019290 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-06 00:14:10.056938 | controller | skipping: Conditional result was False
2025-10-06 00:14:10.074888 | 
2025-10-06 00:14:10.075024 | TASK [include_role : remove-zuul-sshkey]
2025-10-06 00:14:10.095336 | controller | skipping: Conditional result was False
2025-10-06 00:14:10.108401 | 
2025-10-06 00:14:10.108544 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-06 00:14:10.406464 | controller | ok: "logs"
2025-10-06 00:14:10.406914 | controller | ok: All items complete
2025-10-06 00:14:10.406966 | 
2025-10-06 00:14:10.592269 | controller | ok: "artifacts"
2025-10-06 00:14:10.831067 | controller | ok: "docs"
2025-10-06 00:14:10.850459 | 
2025-10-06 00:14:10.850664 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-06 00:14:11.111286 | controller | changed: "logs"
2025-10-06 00:14:11.319512 | controller | changed: "artifacts"
2025-10-06 00:14:11.524409 | controller | changed: "docs"
2025-10-06 00:14:11.569997 | 
2025-10-06 00:14:11.570148 | PLAY RECAP
2025-10-06 00:14:11.570200 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-06 00:14:11.570227 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-06 00:14:11.570245 | 
2025-10-06 00:14:11.801622 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-06 00:14:11.802591 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-06 00:14:12.450984 | 
2025-10-06 00:14:12.451144 | PLAY [all]
2025-10-06 00:14:12.481914 | 
2025-10-06 00:14:12.482098 | TASK [Install binary dependencies]
2025-10-06 00:14:12.556331 | controller | ok
2025-10-06 00:14:12.593039 | 
2025-10-06 00:14:12.593237 | TASK [bindep : Include find tasks]
2025-10-06 00:14:12.677903 | controller | ok
2025-10-06 00:14:12.688811 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-06 00:14:12.695617 | 
2025-10-06 00:14:12.695741 | TASK [bindep : Look for bindep.txt]
2025-10-06 00:14:13.565542 | controller | ok
2025-10-06 00:14:13.572861 | 
2025-10-06 00:14:13.572941 | TASK [bindep : Define bindep_file fact]
2025-10-06 00:14:13.632251 | controller | skipping: Conditional result was False
2025-10-06 00:14:13.640299 | 
2025-10-06 00:14:13.640378 | TASK [bindep : Look for other-requirements.txt]
2025-10-06 00:14:13.861874 | controller | ok
2025-10-06 00:14:13.869446 | 
2025-10-06 00:14:13.869535 | TASK [bindep : Define bindep_file fact]
2025-10-06 00:14:13.902712 | controller | skipping: Conditional result was False
2025-10-06 00:14:13.912443 | 
2025-10-06 00:14:13.912630 | TASK [bindep : Look for bindep fallback file]
2025-10-06 00:14:13.967187 | controller | skipping: Conditional result was False
2025-10-06 00:14:13.978105 | 
2025-10-06 00:14:13.978212 | TASK [bindep : Define bindep_file fact]
2025-10-06 00:14:14.026926 | controller | skipping: Conditional result was False
2025-10-06 00:14:14.038433 | 
2025-10-06 00:14:14.038596 | TASK [bindep : Include bindep tasks]
2025-10-06 00:14:14.101753 | controller | skipping: Conditional result was False
2025-10-06 00:14:14.112169 | 
2025-10-06 00:14:14.112290 | TASK [bindep : Include install tasks]
2025-10-06 00:14:14.175913 | controller | skipping: Conditional result was False
2025-10-06 00:14:14.190805 | 
2025-10-06 00:14:14.190948 | LOOP [bindep : Include package tasks]
2025-10-06 00:14:14.330422 | 
2025-10-06 00:14:14.330821 | TASK [Run test-setup role]
2025-10-06 00:14:14.365577 | controller | ok
2025-10-06 00:14:14.391742 | 
2025-10-06 00:14:14.391887 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-06 00:14:14.617154 | controller | ok
2025-10-06 00:14:14.635134 | 
2025-10-06 00:14:14.635704 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-06 00:14:15.185069 | controller | skipping: Conditional result was False
2025-10-06 00:14:15.223996 | 
2025-10-06 00:14:15.224135 | PLAY RECAP
2025-10-06 00:14:15.224182 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-06 00:14:15.224202 | 
2025-10-06 00:14:15.386446 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-06 00:14:15.387441 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-06 00:14:16.078374 | 
2025-10-06 00:14:16.078622 | PLAY [controller]
2025-10-06 00:14:16.102892 | 
2025-10-06 00:14:16.103020 | TASK [Create the /root directory]
2025-10-06 00:14:16.698016 | controller | ok
2025-10-06 00:14:16.709910 | 
2025-10-06 00:14:16.716343 | TASK [Install glibc-langpack-en]
2025-10-06 00:14:20.835028 | controller | ok: Nothing to do
2025-10-06 00:14:20.841793 | 
2025-10-06 00:14:20.841870 | TASK [Ensure controller directory exists]
2025-10-06 00:14:21.056442 | controller | changed
2025-10-06 00:14:21.062572 | 
2025-10-06 00:14:21.062645 | TASK [Install container runtime]
2025-10-06 00:14:21.136868 | controller | ok
2025-10-06 00:14:21.192225 | 
2025-10-06 00:14:21.192391 | LOOP [ensure-podman : Find distribution installation]
2025-10-06 00:14:21.228120 | controller | ok: "/var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-06 00:14:21.242345 | controller | included: /var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-06 00:14:21.250307 | 
2025-10-06 00:14:21.250410 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-06 00:15:27.820440 | controller | changed
2025-10-06 00:15:27.831172 | 
2025-10-06 00:15:27.831310 | TASK [ensure-podman : Fetch podman version]
2025-10-06 00:15:28.446068 | controller | Client:       Podman Engine
2025-10-06 00:15:28.475268 | controller | Version:      4.6.2
2025-10-06 00:15:28.475316 | controller | API Version:  4.6.2
2025-10-06 00:15:28.475324 | controller | Go Version:   go1.19.12
2025-10-06 00:15:28.475343 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-06 00:15:28.475351 | controller | OS/Arch:      linux/amd64
2025-10-06 00:15:28.886874 | controller | ok: Runtime: 0:00:00.200554
2025-10-06 00:15:28.900438 | 
2025-10-06 00:15:28.900799 | TASK [ensure-podman : Print podman version installed]
2025-10-06 00:15:28.933123 | Podman version: Client:       Podman Engine
2025-10-06 00:15:28.933317 | Version:      4.6.2
2025-10-06 00:15:28.933345 | API Version:  4.6.2
2025-10-06 00:15:28.933365 | Go Version:   go1.19.12
2025-10-06 00:15:28.933383 | Built:        Mon Aug 28 19:38:31 2023
2025-10-06 00:15:28.933404 | OS/Arch:      linux/amd64
2025-10-06 00:15:28.939397 | 
2025-10-06 00:15:28.939467 | TASK [ensure-podman : Validate podman engine]
2025-10-06 00:15:29.471155 | controller | skipping: Conditional result was False
2025-10-06 00:15:29.486043 | 
2025-10-06 00:15:29.486234 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-06 00:15:29.506345 | controller | skipping: Conditional result was False
2025-10-06 00:15:29.533099 | 
2025-10-06 00:15:29.533315 | TASK [Ensure python3.8 is present]
2025-10-06 00:15:29.564184 | controller | skipping: Conditional result was False
2025-10-06 00:15:29.575346 | 
2025-10-06 00:15:29.575479 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-06 00:15:29.599590 | controller | ok
2025-10-06 00:15:29.621847 | 
2025-10-06 00:15:29.622030 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-06 00:15:31.176889 | controller | ok: Nothing to do
2025-10-06 00:15:31.186318 | 
2025-10-06 00:15:31.186485 | TASK [our-ensure-python : Also install python3-devel]
2025-10-06 00:15:40.268829 | controller | changed
2025-10-06 00:15:40.282038 | 
2025-10-06 00:15:40.282219 | TASK [Run ensure-virtualenv role]
2025-10-06 00:15:40.304989 | controller | ok
2025-10-06 00:15:40.328450 | 
2025-10-06 00:15:40.328577 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-06 00:15:40.599326 | controller | /usr/bin/virtualenv
2025-10-06 00:15:40.917110 | controller | ok: Runtime: 0:00:00.005336
2025-10-06 00:15:40.933804 | 
2025-10-06 00:15:40.933990 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-06 00:15:40.963934 | controller | skipping: Conditional result was False
2025-10-06 00:15:40.964276 | controller | ok: All items complete
2025-10-06 00:15:40.964314 | 
2025-10-06 00:15:40.989189 | 
2025-10-06 00:15:40.989417 | TASK [Find the full path of the Python interpreter]
2025-10-06 00:15:41.212004 | controller | /usr/bin/python3.10
2025-10-06 00:15:41.535933 | controller | ok
2025-10-06 00:15:41.552333 | 
2025-10-06 00:15:41.552522 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-06 00:15:42.615042 | controller | created virtual environment CPython3.10.13.final.0-64 in 572ms
2025-10-06 00:15:42.644510 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-06 00:15:42.644616 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2025-10-06 00:15:42.644627 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-06 00:15:42.644640 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-06 00:15:43.114544 | controller | changed
2025-10-06 00:15:43.128469 | 
2025-10-06 00:15:43.128633 | TASK [Set selinux package]
2025-10-06 00:15:43.159484 | controller | ok
2025-10-06 00:15:43.167647 | 
2025-10-06 00:15:43.167768 | TASK [Set selinux package (Fedora)]
2025-10-06 00:15:43.202492 | controller | ok
2025-10-06 00:15:43.209896 | 
2025-10-06 00:15:43.209984 | TASK [Install selinux into virtualenv]
2025-10-06 00:15:44.430968 | controller | Collecting selinux-please-lie-to-me
2025-10-06 00:15:44.472355 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-06 00:15:44.827730 | controller | Collecting setuptools<50.0.0
2025-10-06 00:15:44.867727 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-06 00:15:44.901690 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.0 MB/s eta 0:00:00
2025-10-06 00:15:44.983305 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-06 00:15:44.983554 | controller |   Attempting uninstall: setuptools
2025-10-06 00:15:44.984354 | controller |     Found existing installation: setuptools 62.6.0
2025-10-06 00:15:45.055485 | controller |     Uninstalling setuptools-62.6.0:
2025-10-06 00:15:45.064106 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-06 00:15:45.409818 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-06 00:15:45.536397 | controller |
2025-10-06 00:15:45.614209 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-06 00:15:45.614249 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-10-06 00:15:45.753468 | controller | ok: Runtime: 0:00:02.195074
2025-10-06 00:15:45.770725 | 
2025-10-06 00:15:45.770958 | TASK [Install pytest-forked into virtualenv]
2025-10-06 00:15:46.383383 | controller | Collecting pytest-forked
2025-10-06 00:15:46.439153 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-06 00:15:46.485772 | controller | Collecting py
2025-10-06 00:15:46.489237 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-06 00:15:46.547138 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 1.6 MB/s eta 0:00:00
2025-10-06 00:15:46.681963 | controller | Collecting pytest>=3.10
2025-10-06 00:15:46.687510 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-06 00:15:46.709010 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 21.4 MB/s eta 0:00:00
2025-10-06 00:15:46.783983 | controller | Collecting tomli>=1
2025-10-06 00:15:46.788083 | controller |   Downloading tomli-2.2.1-py3-none-any.whl (14 kB)
2025-10-06 00:15:46.826167 | controller | Collecting exceptiongroup>=1
2025-10-06 00:15:46.829594 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-10-06 00:15:46.876582 | controller | Collecting packaging>=20
2025-10-06 00:15:46.879904 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-06 00:15:46.886402 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 13.1 MB/s eta 0:00:00
2025-10-06 00:15:46.938442 | controller | Collecting pygments>=2.7.2
2025-10-06 00:15:46.944048 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-06 00:15:46.961449 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 83.3 MB/s eta 0:00:00
2025-10-06 00:15:46.987957 | controller | Collecting iniconfig>=1
2025-10-06 00:15:46.992254 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-06 00:15:47.024376 | controller | Collecting pluggy<2,>=1.5
2025-10-06 00:15:47.028020 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-06 00:15:47.084782 | controller | Collecting typing-extensions>=4.6.0
2025-10-06 00:15:47.088520 | controller |   Downloading typing_extensions-4.15.0-py3-none-any.whl (44 kB)
2025-10-06 00:15:47.110639 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.6/44.6 kB 1.9 MB/s eta 0:00:00
2025-10-06 00:15:47.180545 | controller | Installing collected packages: typing-extensions, tomli, pygments, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-10-06 00:15:48.238833 | controller | Successfully installed exceptiongroup-1.3.0 iniconfig-2.1.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0 tomli-2.2.1 typing-extensions-4.15.0
2025-10-06 00:15:48.242957 | controller |
2025-10-06 00:15:48.308684 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-06 00:15:48.308727 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-10-06 00:15:48.346623 | controller | ok: Runtime: 0:00:02.312937
2025-10-06 00:15:48.360742 | 
2025-10-06 00:15:48.360902 | TASK [Update pip]
2025-10-06 00:15:48.897140 | controller | Requirement already satisfied: pip in ./venv/lib/python3.10/site-packages (22.2.2)
2025-10-06 00:15:49.030988 | controller | Collecting pip
2025-10-06 00:15:49.069553 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-06 00:15:49.130877 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.5 MB/s eta 0:00:00
2025-10-06 00:15:49.186510 | controller | Installing collected packages: pip
2025-10-06 00:15:49.186755 | controller |   Attempting uninstall: pip
2025-10-06 00:15:49.187362 | controller |     Found existing installation: pip 22.2.2
2025-10-06 00:15:49.350469 | controller |     Uninstalling pip-22.2.2:
2025-10-06 00:15:49.366991 | controller |       Successfully uninstalled pip-22.2.2
2025-10-06 00:20:26.829758 | [Zuul] Log Stream did not terminate
2025-10-06 00:20:26.830117 | controller | ERROR
2025-10-06 00:20:26.830219 | controller | {
2025-10-06 00:20:26.830248 | controller |   "msg": "Data could not be sent to remote host \"162.253.55.221\". Make sure this host can be reached over ssh: ssh: connect to host 162.253.55.221 port 22: No route to host\r\n",
2025-10-06 00:20:26.830282 | controller |   "unreachable": true
2025-10-06 00:20:26.830306 | controller | }
unreachable
2025-10-06 00:20:26.833312 | 
2025-10-06 00:20:26.833372 | PLAY RECAP
2025-10-06 00:20:26.833418 | controller | ok: 16 changed: 8 unreachable: 1 failed: 0 skipped: 4 rescued: 0 ignored: 0
2025-10-06 00:20:26.833440 | 
2025-10-06 00:20:27.001453 | PRE-RUN END RESULT_UNREACHABLE: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-06 00:20:27.003018 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-06 00:20:27.682818 | 
2025-10-06 00:20:27.683010 | PLAY [all]
2025-10-06 00:20:27.711624 | 
2025-10-06 00:20:27.711871 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-06 00:20:39.291724 | controller | ERROR
2025-10-06 00:20:39.292059 | controller | {
2025-10-06 00:20:39.292117 | controller |   "msg": "Failed to connect to the host via ssh: ssh: connect to host 162.253.55.221 port 22: No route to host",
2025-10-06 00:20:39.292153 | controller |   "unreachable": true
2025-10-06 00:20:39.292200 | controller | }
unreachable
2025-10-06 00:20:39.293810 | 
2025-10-06 00:20:39.293859 | PLAY RECAP
2025-10-06 00:20:39.293908 | controller | ok: 0 changed: 0 unreachable: 1 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-06 00:20:39.293929 | 
2025-10-06 00:20:39.425112 | POST-RUN END RESULT_UNREACHABLE: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-06 00:20:39.427461 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-06 00:20:40.109649 | 
2025-10-06 00:20:40.109833 | PLAY [all:!appliance*]
2025-10-06 00:20:40.137561 | 
2025-10-06 00:20:40.137841 | TASK [unregister the node]
2025-10-06 00:20:42.345232 | [controller] Waiting on logger
2025-10-06 00:20:50.617655 | controller | skipping: Conditional result was False
2025-10-06 00:20:50.631622 | 
2025-10-06 00:20:50.631855 | TASK [include_role : fetch-output]
2025-10-06 00:20:50.693843 | controller | ok
2025-10-06 00:20:50.737635 | 
2025-10-06 00:20:50.737914 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-06 00:20:50.827763 | controller | skipping: Conditional result was False
2025-10-06 00:20:50.835639 | 
2025-10-06 00:20:50.835772 | TASK [fetch-output : Set log path for single node]
2025-10-06 00:20:50.914344 | controller | ok
2025-10-06 00:20:50.924187 | 
2025-10-06 00:20:50.924295 | LOOP [fetch-output : Ensure local output dirs]
2025-10-06 00:20:51.404962 | controller -> localhost | ok: "/var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/logs"
2025-10-06 00:20:51.759718 | controller -> localhost | changed: "/var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/artifacts"
2025-10-06 00:20:51.984452 | controller -> localhost | changed: "/var/lib/zuul/builds/b2e3c6fc1cfa430785291cc2ad72f074/work/docs"
2025-10-06 00:20:51.997576 | 
2025-10-06 00:20:51.997800 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-06 00:20:52.781428 | controller | changed:
2025-10-06 00:20:52.781911 | controller | .d..t...... ./
2025-10-06 00:20:52.781981 | controller | cd+++++++++ controller/
2025-10-06 00:20:52.782052 | controller | changed: All items complete
2025-10-06 00:20:52.782127 | 
2025-10-06 00:20:53.350522 | controller | changed: .d..t...... ./
2025-10-06 00:20:53.922517 | controller | changed: .d..t...... ./
2025-10-06 00:20:53.961767 | 
2025-10-06 00:20:53.962021 | TASK [include_role : fetch-output-openshift]
2025-10-06 00:20:53.992626 | controller | skipping: Conditional result was False
2025-10-06 00:20:54.009439 | 
2025-10-06 00:20:54.009625 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-06 00:20:54.071448 | controller | skipping: Conditional result was False
2025-10-06 00:20:54.085001 | controller | skipping: Conditional result was False
2025-10-06 00:20:54.129137 | 
2025-10-06 00:20:54.129298 | PLAY [localhost]
2025-10-06 00:20:54.142997 | 
2025-10-06 00:20:54.143118 | TASK [Run Zuul manifest role]
2025-10-06 00:20:54.163931 | localhost | ok
2025-10-06 00:20:54.177844 | 
2025-10-06 00:20:54.177952 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-06 00:20:54.637846 | localhost | changed
2025-10-06 00:20:54.644863 | 
2025-10-06 00:20:54.644952 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-06 00:20:54.692015 | localhost | ok
2025-10-06 00:20:54.710893 | 
2025-10-06 00:20:54.711030 | TASK [Set zuul-log-path fact]
2025-10-06 00:20:54.733613 | localhost | ok
2025-10-06 00:20:54.757791 | 
2025-10-06 00:20:54.758011 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-06 00:20:54.789223 | localhost | ok
2025-10-06 00:20:54.798380 | 
2025-10-06 00:20:54.798469 | LOOP [Run upload-logs-swift role]
2025-10-06 00:20:54.846280 | localhost | Output suppressed because no_log was given
2025-10-06 00:20:54.874182 | 
2025-10-06 00:20:54.874332 | TASK [Set zuul-log-path fact]
2025-10-06 00:20:54.911518 | localhost | skipping: Conditional result was False
2025-10-06 00:20:54.921961 | 
2025-10-06 00:20:54.922113 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-06 00:20:55.363282 | localhost -> localhost | ok: Runtime: 0:00:00.007169
2025-10-06 00:20:55.369601 | 
2025-10-06 00:20:55.369711 | TASK [upload-logs-swift : Upload logs to swift]