2026-01-21 00:12:46.673760 | Job console starting...
2026-01-21 00:12:46.683155 | Updating repositories
2026-01-21 00:12:46.913289 | Preparing job workspace
2026-01-21 00:12:52.260475 | Running Ansible setup...
2026-01-21 00:12:57.006202 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:12:57.660591 | 
2026-01-21 00:12:57.660744 | PLAY [localhost]
2026-01-21 00:12:57.669764 | 
2026-01-21 00:12:57.669863 | TASK [Gathering Facts]
2026-01-21 00:12:58.649132 | localhost | ok
2026-01-21 00:12:58.664526 | 
2026-01-21 00:12:58.664659 | TASK [Setup log path fact]
2026-01-21 00:12:58.683799 | localhost | ok
2026-01-21 00:12:58.700558 | 
2026-01-21 00:12:58.700694 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:12:58.730154 | localhost | ok
2026-01-21 00:12:58.740246 | 
2026-01-21 00:12:58.740374 | TASK [emit-job-header : Print job information]
2026-01-21 00:12:58.769964 | # Job Information
2026-01-21 00:12:58.770162 | Ansible Version: 2.15.12
2026-01-21 00:12:58.770207 | Job: ansible-test-sanity-docker-milestone
2026-01-21 00:12:58.770237 | Pipeline: periodic
2026-01-21 00:12:58.770263 | Executor: ze01.softwarefactory-project.io
2026-01-21 00:12:58.770307 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-21 00:12:58.770337 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/89b/ansible/89b60f6826054634a1f1774378ca2081/
2026-01-21 00:12:58.770364 | Event ID: 08cfdb9560914df89453f509f8798614
2026-01-21 00:12:58.775176 | 
2026-01-21 00:12:58.775265 | LOOP [emit-job-header : Print node information]
2026-01-21 00:12:58.898231 | localhost | ok:
2026-01-21 00:12:58.898473 | localhost | # Node Information
2026-01-21 00:12:58.898510 | localhost | Inventory Hostname: controller
2026-01-21 00:12:58.898538 | localhost | Hostname: np0005589745
2026-01-21 00:12:58.898565 | localhost | Username: zuul
2026-01-21 00:12:58.898593 | localhost | Distro: Fedora 37
2026-01-21 00:12:58.898619 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-21 00:12:58.898644 | localhost | Region: ca-ymq-1
2026-01-21 00:12:58.898668 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-21 00:12:58.898692 | localhost | Product Name: OpenStack Nova
2026-01-21 00:12:58.898716 | localhost | Interface IP: 162.253.55.62
2026-01-21 00:12:58.913625 | 
2026-01-21 00:12:58.913777 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-21 00:12:59.349918 | localhost -> localhost | changed
2026-01-21 00:12:59.363517 | 
2026-01-21 00:12:59.363707 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-21 00:13:00.253085 | localhost -> localhost | changed
2026-01-21 00:13:00.278309 | 
2026-01-21 00:13:00.278828 | PLAY [all:!appliance*]
2026-01-21 00:13:00.299707 | 
2026-01-21 00:13:00.299851 | TASK [include_role : start-zuul-console]
2026-01-21 00:13:00.322063 | controller | ok
2026-01-21 00:13:00.345923 | 
2026-01-21 00:13:00.346082 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-21 00:13:00.758617 | controller | ok
2026-01-21 00:13:00.784646 | 
2026-01-21 00:13:00.784785 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-21 00:13:01.881395 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-21 00:13:01.893193 | 
2026-01-21 00:13:01.893523 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-21 00:13:02.442721 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.451718 | 
2026-01-21 00:13:02.451846 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-21 00:13:02.475962 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.483598 | 
2026-01-21 00:13:02.483704 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-21 00:13:02.499596 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.507164 | 
2026-01-21 00:13:02.507309 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-21 00:13:02.523344 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.532894 | 
2026-01-21 00:13:02.533030 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-21 00:13:02.557532 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.566956 | 
2026-01-21 00:13:02.567100 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-21 00:13:02.592485 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.606963 | 
2026-01-21 00:13:02.607103 | TASK [Disable Fedora Modular]
2026-01-21 00:13:02.841633 | controller | changed
2026-01-21 00:13:02.847737 | 
2026-01-21 00:13:02.847843 | TASK [Enable EPEL]
2026-01-21 00:13:02.879078 | controller | skipping: Conditional result was False
2026-01-21 00:13:02.897575 | 
2026-01-21 00:13:02.897814 | TASK [Register the RHEL node]
2026-01-21 00:13:03.472294 | 
2026-01-21 00:13:03.472479 | TASK [Show the subscription-manager status]
2026-01-21 00:13:04.047843 | controller | skipping: Conditional result was False
2026-01-21 00:13:04.054945 | 
2026-01-21 00:13:04.055061 | TASK [Enable EPEL on RHEL]
2026-01-21 00:13:04.587972 | controller | skipping: Conditional result was False
2026-01-21 00:13:04.595255 | 
2026-01-21 00:13:04.595390 | TASK [Install git and tox]
2026-01-21 00:14:26.751089 | controller | changed
2026-01-21 00:14:26.766757 | 
2026-01-21 00:14:26.766896 | TASK [include_role : prepare-workspace]
2026-01-21 00:14:26.803279 | controller | ok
2026-01-21 00:14:26.829222 | 
2026-01-21 00:14:26.829616 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-21 00:14:27.046948 | controller | ok
2026-01-21 00:14:27.056391 | 
2026-01-21 00:14:27.056527 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-21 00:14:40.291498 | controller | Output suppressed because no_log was given
2026-01-21 00:14:40.343157 | 
2026-01-21 00:14:40.343295 | TASK [include_role : prepare-workspace-openshift]
2026-01-21 00:14:40.358249 | controller | skipping: Conditional result was False
2026-01-21 00:14:40.385854 | 
2026-01-21 00:14:40.385974 | PLAY [all:!appliance]
2026-01-21 00:14:40.408786 | 
2026-01-21 00:14:40.408896 | TASK [Run add-build-sshkey role (RSA)]
2026-01-21 00:14:40.429059 | controller | ok
2026-01-21 00:14:40.445367 | 
2026-01-21 00:14:40.445470 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:14:40.663242 | controller -> localhost | ok
2026-01-21 00:14:40.671712 | 
2026-01-21 00:14:40.671822 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:14:40.693035 | controller | ok
2026-01-21 00:14:40.707792 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:14:40.714747 | 
2026-01-21 00:14:40.714863 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:14:41.141867 | controller -> localhost | Generating public/private rsa key pair.
2026-01-21 00:14:41.142183 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_rsa.
2026-01-21 00:14:41.142230 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_rsa.pub.
2026-01-21 00:14:41.142261 | controller -> localhost | The key fingerprint is:
2026-01-21 00:14:41.142290 | controller -> localhost | SHA256:i+j9zovOJkiAjwz9/I/ubML8nr/2mbgB7l4CZQXo15g zuul-build-sshkey
2026-01-21 00:14:41.142328 | controller -> localhost | The key's randomart image is:
2026-01-21 00:14:41.142365 | controller -> localhost | +---[RSA 2048]----+
2026-01-21 00:14:41.142394 | controller -> localhost | |     ....        |
2026-01-21 00:14:41.142422 | controller -> localhost | |    .  .         |
2026-01-21 00:14:41.142458 | controller -> localhost | |.. .  o+         |
2026-01-21 00:14:41.142495 | controller -> localhost | |+ . .oE .        |
2026-01-21 00:14:41.142531 | controller -> localhost | |o+ o... S        |
2026-01-21 00:14:41.142571 | controller -> localhost | |..o o+ o .       |
2026-01-21 00:14:41.142608 | controller -> localhost | | . +..+ +        |
2026-01-21 00:14:41.142638 | controller -> localhost | |  ..==+B.o o     |
2026-01-21 00:14:41.142666 | controller -> localhost | |    .%/*@=+      |
2026-01-21 00:14:41.142696 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:14:41.142764 | controller -> localhost | ok: Runtime: 0:00:00.042481
2026-01-21 00:14:41.157774 | 
2026-01-21 00:14:41.157912 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:14:41.201988 | controller | ok
2026-01-21 00:14:41.219593 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:14:41.231719 | 
2026-01-21 00:14:41.231854 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:14:41.246669 | controller | skipping: Conditional result was False
2026-01-21 00:14:41.253583 | 
2026-01-21 00:14:41.253705 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:14:41.677747 | controller | changed
2026-01-21 00:14:41.691134 | 
2026-01-21 00:14:41.691307 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:14:41.938862 | controller | ok
2026-01-21 00:14:41.956132 | 
2026-01-21 00:14:41.956338 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:14:42.575809 | controller | changed
2026-01-21 00:14:42.582671 | 
2026-01-21 00:14:42.582792 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:14:43.210586 | controller | changed
2026-01-21 00:14:43.219433 | 
2026-01-21 00:14:43.219539 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:14:43.245428 | controller | skipping: Conditional result was False
2026-01-21 00:14:43.254763 | 
2026-01-21 00:14:43.254908 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:14:43.669233 | controller -> localhost | changed
2026-01-21 00:14:43.704228 | 
2026-01-21 00:14:43.704577 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:14:44.016554 | controller -> localhost | Identity added: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_rsa (zuul-build-sshkey)
2026-01-21 00:14:44.016971 | controller -> localhost | ok: Runtime: 0:00:00.011887
2026-01-21 00:14:44.038962 | 
2026-01-21 00:14:44.039243 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:14:44.407108 | controller | ok
2026-01-21 00:14:44.415247 | 
2026-01-21 00:14:44.415380 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:14:44.440805 | controller | skipping: Conditional result was False
2026-01-21 00:14:44.456780 | 
2026-01-21 00:14:44.456919 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-21 00:14:44.479654 | controller | ok
2026-01-21 00:14:44.504221 | 
2026-01-21 00:14:44.504365 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:14:44.754695 | controller -> localhost | ok
2026-01-21 00:14:44.761984 | 
2026-01-21 00:14:44.762093 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:14:44.783232 | controller | ok
2026-01-21 00:14:44.794457 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:14:44.801581 | 
2026-01-21 00:14:44.801679 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:14:45.143206 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-21 00:14:45.143499 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_ecdsa.
2026-01-21 00:14:45.143548 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_ecdsa.pub.
2026-01-21 00:14:45.143606 | controller -> localhost | The key fingerprint is:
2026-01-21 00:14:45.143647 | controller -> localhost | SHA256:nAEQQHR0Bv76XaoZIt39uv3K7q7zUKp8ufzii9PRa2k zuul-build-sshkey
2026-01-21 00:14:45.143685 | controller -> localhost | The key's randomart image is:
2026-01-21 00:14:45.143723 | controller -> localhost | +---[ECDSA 521]---+
2026-01-21 00:14:45.143762 | controller -> localhost | | o+o*++          |
2026-01-21 00:14:45.143798 | controller -> localhost | |   o o .         |
2026-01-21 00:14:45.143831 | controller -> localhost | |    .   .        |
2026-01-21 00:14:45.143856 | controller -> localhost | |     . . o       |
2026-01-21 00:14:45.143880 | controller -> localhost | |      . S..      |
2026-01-21 00:14:45.143904 | controller -> localhost | |   . o ..o.      |
2026-01-21 00:14:45.143928 | controller -> localhost | |  . + o.+o.o     |
2026-01-21 00:14:45.143952 | controller -> localhost | |   . +.B*BE      |
2026-01-21 00:14:45.143975 | controller -> localhost | |      B=@^@o.    |
2026-01-21 00:14:45.143999 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:14:45.144100 | controller -> localhost | ok: Runtime: 0:00:00.008205
2026-01-21 00:14:45.154107 | 
2026-01-21 00:14:45.154227 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:14:45.192202 | controller | ok
2026-01-21 00:14:45.203558 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:14:45.218102 | 
2026-01-21 00:14:45.218249 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:14:45.233410 | controller | skipping: Conditional result was False
2026-01-21 00:14:45.242137 | 
2026-01-21 00:14:45.242455 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:14:45.497195 | controller | changed
2026-01-21 00:14:45.503786 | 
2026-01-21 00:14:45.503898 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:14:45.740159 | controller | ok
2026-01-21 00:14:45.746716 | 
2026-01-21 00:14:45.746819 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:14:46.352581 | controller | changed
2026-01-21 00:14:46.361567 | 
2026-01-21 00:14:46.361669 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:14:46.975736 | controller | changed
2026-01-21 00:14:46.991228 | 
2026-01-21 00:14:46.991323 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:14:47.016815 | controller | skipping: Conditional result was False
2026-01-21 00:14:47.034442 | 
2026-01-21 00:14:47.034601 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:14:47.315309 | controller -> localhost | changed
2026-01-21 00:14:47.377604 | 
2026-01-21 00:14:47.377746 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:14:47.682718 | controller -> localhost | Identity added: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/89b60f6826054634a1f1774378ca2081_id_ecdsa (zuul-build-sshkey)
2026-01-21 00:14:47.683275 | controller -> localhost | ok: Runtime: 0:00:00.014156
2026-01-21 00:14:47.706870 | 
2026-01-21 00:14:47.707061 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:19:49.430984 | controller | ok
2026-01-21 00:19:49.444729 | 
2026-01-21 00:19:49.444878 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:19:49.493936 | controller | skipping: Conditional result was False
2026-01-21 00:19:49.526703 | 
2026-01-21 00:19:49.527108 | TASK [include_role : remove-zuul-sshkey]
2026-01-21 00:19:49.555408 | controller | skipping: Conditional result was False
2026-01-21 00:19:49.565489 | 
2026-01-21 00:19:49.565590 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-21 00:19:49.803192 | controller | ok: "logs"
2026-01-21 00:19:49.803489 | controller | ok: All items complete
2026-01-21 00:19:49.803523 | 
2026-01-21 00:19:50.003217 | controller | ok: "artifacts"
2026-01-21 00:19:50.202705 | controller | ok: "docs"
2026-01-21 00:19:50.226481 | 
2026-01-21 00:19:50.226786 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-21 00:19:50.452481 | controller | changed: "logs"
2026-01-21 00:19:50.653969 | controller | changed: "artifacts"
2026-01-21 00:19:50.842090 | controller | changed: "docs"
2026-01-21 00:19:50.893395 | 
2026-01-21 00:19:50.893489 | PLAY RECAP
2026-01-21 00:19:50.893535 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-21 00:19:50.893562 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-21 00:19:50.893582 | 
2026-01-21 00:19:51.022895 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:19:51.023832 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:19:51.714447 | 
2026-01-21 00:19:51.714598 | PLAY [all]
2026-01-21 00:19:51.741282 | 
2026-01-21 00:19:51.741422 | TASK [Install binary dependencies]
2026-01-21 00:19:51.795293 | controller | ok
2026-01-21 00:19:51.823960 | 
2026-01-21 00:19:51.824153 | TASK [bindep : Include find tasks]
2026-01-21 00:19:51.878646 | controller | ok
2026-01-21 00:19:51.891820 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-21 00:19:51.902762 | 
2026-01-21 00:19:51.902885 | TASK [bindep : Look for bindep.txt]
2026-01-21 00:19:52.480740 | controller | ok
2026-01-21 00:19:52.489873 | 
2026-01-21 00:19:52.489997 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:19:52.505101 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.515252 | 
2026-01-21 00:19:52.515381 | TASK [bindep : Look for other-requirements.txt]
2026-01-21 00:19:52.727423 | controller | ok
2026-01-21 00:19:52.741657 | 
2026-01-21 00:19:52.741859 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:19:52.769282 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.779565 | 
2026-01-21 00:19:52.779726 | TASK [bindep : Look for bindep fallback file]
2026-01-21 00:19:52.825998 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.837214 | 
2026-01-21 00:19:52.837377 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:19:52.863923 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.874121 | 
2026-01-21 00:19:52.874298 | TASK [bindep : Include bindep tasks]
2026-01-21 00:19:52.900699 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.910843 | 
2026-01-21 00:19:52.910994 | TASK [bindep : Include install tasks]
2026-01-21 00:19:52.936786 | controller | skipping: Conditional result was False
2026-01-21 00:19:52.945998 | 
2026-01-21 00:19:52.946565 | LOOP [bindep : Include package tasks]
2026-01-21 00:19:53.021416 | 
2026-01-21 00:19:53.021626 | TASK [Run test-setup role]
2026-01-21 00:19:53.046174 | controller | ok
2026-01-21 00:19:53.072210 | 
2026-01-21 00:19:53.072342 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-21 00:19:53.274838 | controller | ok
2026-01-21 00:19:53.280824 | 
2026-01-21 00:19:53.280887 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-21 00:19:53.812530 | controller | skipping: Conditional result was False
2026-01-21 00:19:53.842824 | 
2026-01-21 00:19:53.842953 | PLAY RECAP
2026-01-21 00:19:53.842997 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:19:53.843039 | 
2026-01-21 00:19:53.966167 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:19:53.967319 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:19:54.639173 | 
2026-01-21 00:19:54.639334 | PLAY [controller]
2026-01-21 00:19:54.668200 | 
2026-01-21 00:19:54.668368 | TASK [Create the /root directory]
2026-01-21 00:19:55.252621 | controller | ok
2026-01-21 00:19:55.267269 | 
2026-01-21 00:19:55.267478 | TASK [Install glibc-langpack-en]
2026-01-21 00:19:59.098803 | controller | ok: Nothing to do
2026-01-21 00:19:59.106172 | 
2026-01-21 00:19:59.106316 | TASK [Ensure controller directory exists]
2026-01-21 00:19:59.321803 | controller | changed
2026-01-21 00:19:59.328259 | 
2026-01-21 00:19:59.328347 | TASK [Install container runtime]
2026-01-21 00:19:59.379702 | controller | ok
2026-01-21 00:19:59.416164 | 
2026-01-21 00:19:59.416290 | LOOP [ensure-podman : Find distribution installation]
2026-01-21 00:19:59.452247 | controller | ok: "/var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-21 00:19:59.472599 | controller | included: /var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-21 00:19:59.482032 | 
2026-01-21 00:19:59.482177 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-21 00:21:04.307493 | controller | changed
2026-01-21 00:21:04.318069 | 
2026-01-21 00:21:04.318355 | TASK [ensure-podman : Fetch podman version]
2026-01-21 00:21:04.851970 | controller | Client:       Podman Engine
2026-01-21 00:21:04.873819 | controller | Version:      4.6.2
2026-01-21 00:21:04.873844 | controller | API Version:  4.6.2
2026-01-21 00:21:04.873850 | controller | Go Version:   go1.19.12
2026-01-21 00:21:04.873862 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:21:04.873868 | controller | OS/Arch:      linux/amd64
2026-01-21 00:21:05.361617 | controller | ok: Runtime: 0:00:00.186501
2026-01-21 00:21:05.377897 | 
2026-01-21 00:21:05.378108 | TASK [ensure-podman : Print podman version installed]
2026-01-21 00:21:05.415169 | Podman version: Client:       Podman Engine
2026-01-21 00:21:05.415396 | Version:      4.6.2
2026-01-21 00:21:05.415451 | API Version:  4.6.2
2026-01-21 00:21:05.415496 | Go Version:   go1.19.12
2026-01-21 00:21:05.415535 | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:21:05.415576 | OS/Arch:      linux/amd64
2026-01-21 00:21:05.424966 | 
2026-01-21 00:21:05.425145 | TASK [ensure-podman : Validate podman engine]
2026-01-21 00:21:05.965488 | controller | skipping: Conditional result was False
2026-01-21 00:21:05.972272 | 
2026-01-21 00:21:05.972372 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-21 00:21:05.996802 | controller | skipping: Conditional result was False
2026-01-21 00:21:06.009176 | 
2026-01-21 00:21:06.009305 | TASK [Ensure python3.8 is present]
2026-01-21 00:21:06.033830 | controller | skipping: Conditional result was False
2026-01-21 00:21:06.040536 | 
2026-01-21 00:21:06.040636 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-21 00:21:06.062004 | controller | ok
2026-01-21 00:21:06.083757 | 
2026-01-21 00:21:06.083874 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-21 00:21:07.515950 | controller | ok: Nothing to do
2026-01-21 00:21:07.529580 | 
2026-01-21 00:21:07.529702 | TASK [our-ensure-python : Also install python3-devel]
2026-01-21 00:21:15.994433 | controller | changed
2026-01-21 00:21:16.006394 | 
2026-01-21 00:21:16.006512 | TASK [Run ensure-virtualenv role]
2026-01-21 00:21:16.034920 | controller | ok
2026-01-21 00:21:16.057152 | 
2026-01-21 00:21:16.057274 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-21 00:21:16.258683 | controller | /usr/bin/virtualenv
2026-01-21 00:21:16.590967 | controller | ok: Runtime: 0:00:00.005337
2026-01-21 00:21:16.599191 | 
2026-01-21 00:21:16.599338 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-21 00:21:16.623547 | controller | skipping: Conditional result was False
2026-01-21 00:21:16.623853 | controller | ok: All items complete
2026-01-21 00:21:16.623889 | 
2026-01-21 00:21:16.651801 | 
2026-01-21 00:21:16.652064 | TASK [Find the full path of the Python interpreter]
2026-01-21 00:21:16.912317 | controller | /usr/bin/python3
2026-01-21 00:21:17.226086 | controller | ok
2026-01-21 00:21:17.241349 | 
2026-01-21 00:21:17.241533 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-21 00:21:18.031436 | controller | created virtual environment CPython3.11.0.final.0-64 in 440ms
2026-01-21 00:21:18.049304 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-21 00:21:18.049342 | 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-01-21 00:21:18.049352 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-21 00:21:18.049366 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-21 00:21:18.306009 | controller | changed
2026-01-21 00:21:18.313845 | 
2026-01-21 00:21:18.313984 | TASK [Set selinux package]
2026-01-21 00:21:18.341454 | controller | ok
2026-01-21 00:21:18.353119 | 
2026-01-21 00:21:18.353273 | TASK [Set selinux package (Fedora)]
2026-01-21 00:21:18.387678 | controller | ok
2026-01-21 00:21:18.395458 | 
2026-01-21 00:21:18.395580 | TASK [Install selinux into virtualenv]
2026-01-21 00:21:19.623291 | controller | Collecting selinux-please-lie-to-me
2026-01-21 00:21:19.661371 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-21 00:21:19.958139 | controller | Collecting setuptools<50.0.0
2026-01-21 00:21:19.962698 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-21 00:21:20.000158 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.4 MB/s eta 0:00:00
2026-01-21 00:21:20.085508 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-21 00:21:20.085725 | controller |   Attempting uninstall: setuptools
2026-01-21 00:21:20.088172 | controller |     Found existing installation: setuptools 62.6.0
2026-01-21 00:21:20.150961 | controller |     Uninstalling setuptools-62.6.0:
2026-01-21 00:21:20.159183 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-21 00:21:20.504744 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-21 00:21:20.630911 | controller |
2026-01-21 00:21:20.712978 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:21:20.713018 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:21:20.945856 | controller | ok: Runtime: 0:00:02.085330
2026-01-21 00:21:20.951818 | 
2026-01-21 00:21:20.951900 | TASK [Install pytest-forked into virtualenv]
2026-01-21 00:21:21.512604 | controller | Collecting pytest-forked
2026-01-21 00:21:21.596841 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-21 00:21:21.651868 | controller | Collecting py
2026-01-21 00:21:21.696089 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-21 00:21:21.710751 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 7.4 MB/s eta 0:00:00
2026-01-21 00:21:21.809870 | controller | Collecting pytest>=3.10
2026-01-21 00:21:21.837508 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-21 00:21:21.856806 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.9 MB/s eta 0:00:00
2026-01-21 00:21:21.891167 | controller | Collecting iniconfig>=1.0.1
2026-01-21 00:21:21.898820 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-21 00:21:21.938725 | controller | Collecting packaging>=22
2026-01-21 00:21:21.942084 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-21 00:21:21.951199 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.7 MB/s eta 0:00:00
2026-01-21 00:21:22.006613 | controller | Collecting pluggy<2,>=1.5
2026-01-21 00:21:22.023349 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-21 00:21:22.084496 | controller | Collecting pygments>=2.7.2
2026-01-21 00:21:22.092324 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-21 00:21:22.108620 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 89.9 MB/s eta 0:00:00
2026-01-21 00:21:22.175772 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-21 00:21:23.222025 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-01-21 00:21:23.230651 | controller |
2026-01-21 00:21:23.294570 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:21:23.294610 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:21:23.496079 | controller | ok: Runtime: 0:00:02.146785
2026-01-21 00:21:23.503115 | 
2026-01-21 00:21:23.503221 | TASK [Update pip]
2026-01-21 00:21:23.987542 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-21 00:21:24.119643 | controller | Collecting pip
2026-01-21 00:21:24.154479 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-21 00:21:24.197909 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 44.1 MB/s eta 0:00:00
2026-01-21 00:21:24.260675 | controller | Installing collected packages: pip
2026-01-21 00:21:24.260886 | controller |   Attempting uninstall: pip
2026-01-21 00:21:24.263038 | controller |     Found existing installation: pip 22.2.2
2026-01-21 00:21:24.399752 | controller |     Uninstalling pip-22.2.2:
2026-01-21 00:21:24.414480 | controller |       Successfully uninstalled pip-22.2.2
2026-01-21 00:21:25.238694 | controller | Successfully installed pip-25.3
2026-01-21 00:21:25.541237 | controller | ok: Runtime: 0:00:01.611832
2026-01-21 00:21:25.550313 | 
2026-01-21 00:21:25.550454 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-21 00:21:25.756167 | controller | changed
2026-01-21 00:21:25.761629 | 
2026-01-21 00:21:25.761691 | TASK [Install ansible into virtualenv]
2026-01-21 00:21:26.244821 | controller | Processing ./src/github.com/ansible/ansible
2026-01-21 00:21:26.248471 | controller |   Installing build dependencies: started
2026-01-21 00:21:27.252279 | controller |   Installing build dependencies: finished with status 'done'
2026-01-21 00:21:28.000294 | controller |   Getting requirements to build wheel: started
2026-01-21 00:21:28.000351 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-21 00:21:28.001397 | controller |   Preparing metadata (pyproject.toml): started
2026-01-21 00:21:28.457286 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-21 00:21:28.459616 | 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-01-21 00:21:28.462291 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-21 00:21:28.804448 | controller | ERROR
2026-01-21 00:21:28.804681 | controller | {
2026-01-21 00:21:28.804722 | controller |   "delta": "0:00:02.559495",
2026-01-21 00:21:28.804749 | controller |   "end": "2026-01-21 00:21:28.524613",
2026-01-21 00:21:28.804775 | controller |   "msg": "non-zero return code",
2026-01-21 00:21:28.804811 | controller |   "rc": 1,
2026-01-21 00:21:28.804838 | controller |   "start": "2026-01-21 00:21:25.965118"
2026-01-21 00:21:28.804863 | controller | }
failure
2026-01-21 00:21:28.806954 | 
2026-01-21 00:21:28.807046 | PLAY RECAP
2026-01-21 00:21:28.807114 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-21 00:21:28.807152 | 
2026-01-21 00:21:28.962245 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:21:28.963309 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:21:29.640431 | 
2026-01-21 00:21:29.640602 | PLAY [all]
2026-01-21 00:21:29.666438 | 
2026-01-21 00:21:29.666595 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-21 00:21:30.039113 | controller | changed: non-zero return code
2026-01-21 00:21:30.048034 | 
2026-01-21 00:21:30.048213 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-21 00:21:30.075039 | controller | skipping: Conditional result was False
2026-01-21 00:21:30.082426 | 
2026-01-21 00:21:30.082578 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-21 00:21:30.117381 | 
2026-01-21 00:21:30.117590 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-21 00:21:30.152736 | 
2026-01-21 00:21:30.152945 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-21 00:21:30.168643 | controller | skipping: Conditional result was False
2026-01-21 00:21:30.177328 | 
2026-01-21 00:21:30.177426 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-21 00:21:30.209179 | 
2026-01-21 00:21:30.209369 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-21 00:21:30.223960 | controller | skipping: Conditional result was False
2026-01-21 00:21:30.232087 | 
2026-01-21 00:21:30.232202 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-21 00:21:30.246660 | controller | skipping: Conditional result was False
2026-01-21 00:21:30.253385 | 
2026-01-21 00:21:30.253492 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-21 00:21:30.267931 | controller | skipping: Conditional result was False
2026-01-21 00:21:30.297226 | 
2026-01-21 00:21:30.297328 | PLAY RECAP
2026-01-21 00:21:30.297370 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:21:30.297390 | 
2026-01-21 00:21:30.418116 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:21:30.419708 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-21 00:21:31.063264 | 
2026-01-21 00:21:31.063401 | PLAY [all:!appliance*]
2026-01-21 00:21:31.089977 | 
2026-01-21 00:21:31.090119 | TASK [unregister the node]
2026-01-21 00:21:31.625979 | controller | skipping: Conditional result was False
2026-01-21 00:21:31.635123 | 
2026-01-21 00:21:31.635277 | TASK [include_role : fetch-output]
2026-01-21 00:21:31.667659 | controller | ok
2026-01-21 00:21:31.694181 | 
2026-01-21 00:21:31.694319 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-21 00:21:31.739676 | controller | skipping: Conditional result was False
2026-01-21 00:21:31.749930 | 
2026-01-21 00:21:31.750129 | TASK [fetch-output : Set log path for single node]
2026-01-21 00:21:31.784465 | controller | ok
2026-01-21 00:21:31.794092 | 
2026-01-21 00:21:31.794254 | LOOP [fetch-output : Ensure local output dirs]
2026-01-21 00:21:32.236594 | controller -> localhost | ok: "/var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/logs"
2026-01-21 00:21:32.486901 | controller -> localhost | changed: "/var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/artifacts"
2026-01-21 00:21:32.720240 | controller -> localhost | changed: "/var/lib/zuul/builds/89b60f6826054634a1f1774378ca2081/work/docs"
2026-01-21 00:21:32.737010 | 
2026-01-21 00:21:32.737204 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-21 00:21:33.378550 | controller | changed:
2026-01-21 00:21:33.378762 | controller | .d..t...... ./
2026-01-21 00:21:33.378790 | controller | cd+++++++++ controller/
2026-01-21 00:21:33.378825 | controller | changed: All items complete
2026-01-21 00:21:33.378846 | 
2026-01-21 00:21:33.846074 | controller | changed: .d..t...... ./
2026-01-21 00:21:34.331608 | controller | changed: .d..t...... ./
2026-01-21 00:21:34.351507 | 
2026-01-21 00:21:34.351663 | TASK [include_role : fetch-output-openshift]
2026-01-21 00:21:34.368574 | controller | skipping: Conditional result was False
2026-01-21 00:21:34.377246 | 
2026-01-21 00:21:34.377408 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-21 00:21:34.408705 | controller | skipping: Conditional result was False
2026-01-21 00:21:34.417978 | controller | skipping: Conditional result was False
2026-01-21 00:21:34.455543 | 
2026-01-21 00:21:34.455664 | PLAY [localhost]
2026-01-21 00:21:34.469624 | 
2026-01-21 00:21:34.469751 | TASK [Run Zuul manifest role]
2026-01-21 00:21:34.488196 | localhost | ok
2026-01-21 00:21:34.504544 | 
2026-01-21 00:21:34.504679 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-21 00:21:34.889592 | localhost | changed
2026-01-21 00:21:34.894742 | 
2026-01-21 00:21:34.894820 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-21 00:21:34.922700 | localhost | ok
2026-01-21 00:21:34.931424 | 
2026-01-21 00:21:34.931496 | TASK [Set zuul-log-path fact]
2026-01-21 00:21:34.948923 | localhost | ok
2026-01-21 00:21:34.965593 | 
2026-01-21 00:21:34.965719 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:21:34.994877 | localhost | ok
2026-01-21 00:21:35.002683 | 
2026-01-21 00:21:35.002755 | LOOP [Run upload-logs-swift role]
2026-01-21 00:21:35.038581 | localhost | Output suppressed because no_log was given
2026-01-21 00:21:35.066541 | 
2026-01-21 00:21:35.066785 | TASK [Set zuul-log-path fact]
2026-01-21 00:21:35.091513 | localhost | skipping: Conditional result was False
2026-01-21 00:21:35.096733 | 
2026-01-21 00:21:35.096851 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-21 00:21:35.570519 | localhost -> localhost | ok: Runtime: 0:00:00.005665
2026-01-21 00:21:35.577359 | 
2026-01-21 00:21:35.577427 | TASK [upload-logs-swift : Upload logs to swift]