PLAY [Prepare] *****************************************************************

TASK [Gathering Facts] *********************************************************
Thursday 02 October 2025  20:00:22 +0000 (0:00:00.013)       0:00:00.013 ******
ok: [instance]

TASK [test_deps : Gather facts if they don't exist] ****************************
Thursday 02 October 2025  20:00:23 +0000 (0:00:00.884)       0:00:00.897 ******
skipping: [instance]

TASK [test_deps : Gather variables for each operating system] ******************
Thursday 02 October 2025  20:00:23 +0000 (0:00:00.019)       0:00:00.917 ******
ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)

TASK [test_deps : Detect mirrors file] *****************************************
Thursday 02 October 2025  20:00:23 +0000 (0:00:00.048)       0:00:00.965 ******
ok: [instance]

TASK [test_deps : Disable ubi host subscription-manager integration] ***********
Thursday 02 October 2025  20:00:23 +0000 (0:00:00.290)       0:00:01.255 ******
ok: [instance]

TASK [test_deps : Disable ubi 9 repos] *****************************************
Thursday 02 October 2025  20:00:23 +0000 (0:00:00.322)       0:00:01.578 ******
ok: [instance] => (item=ubi-9-appstream)
ok: [instance] => (item=ubi-9-baseos)
ok: [instance] => (item=ubi-9-codeready-builder)

TASK [Deploy repo-setup] *******************************************************
Thursday 02 October 2025  20:00:24 +0000 (0:00:00.754)       0:00:02.332 ******

TASK [repo_setup : Ensure directories are present] *****************************
Thursday 02 October 2025  20:00:24 +0000 (0:00:00.062)       0:00:02.395 ******
changed: [instance] => (item=tmp)
changed: [instance] => (item=artifacts/repositories)
changed: [instance] => (item=venv/repo_setup)

TASK [repo_setup : Make sure git-core package is installed] ********************
Thursday 02 October 2025  20:00:25 +0000 (0:00:00.616)       0:00:03.012 ******
ok: [instance]

TASK [repo_setup : Get repo-setup repository] **********************************
Thursday 02 October 2025  20:00:26 +0000 (0:00:00.884)       0:00:03.897 ******
changed: [instance]

TASK [repo_setup : Initialize python venv and install requirements] ************
Thursday 02 October 2025  20:00:27 +0000 (0:00:01.282)       0:00:05.179 ******
changed: [instance]

TASK [repo_setup : Install repo-setup package] *********************************
Thursday 02 October 2025  20:00:35 +0000 (0:00:08.449)       0:00:13.628 ******
changed: [instance]

TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
Thursday 02 October 2025  20:00:36 +0000 (0:00:00.822)       0:00:14.452 ******
skipping: [instance]

TASK [repo_setup : Run repo-setup] *********************************************
Thursday 02 October 2025  20:00:36 +0000 (0:00:00.030)       0:00:14.482 ******
changed: [instance]

TASK [repo_setup : Get component repo] *****************************************
Thursday 02 October 2025  20:00:37 +0000 (0:00:00.895)       0:00:15.378 ******
skipping: [instance]

TASK [repo_setup : Rename component repo] **************************************
Thursday 02 October 2025  20:00:37 +0000 (0:00:00.044)       0:00:15.423 ******
skipping: [instance]

TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
Thursday 02 October 2025  20:00:37 +0000 (0:00:00.046)       0:00:15.469 ******
skipping: [instance]

TASK [repo_setup : Run repo-setup-get-hash] ************************************
Thursday 02 October 2025  20:00:37 +0000 (0:00:00.049)       0:00:15.518 ******
changed: [instance]

TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
Thursday 02 October 2025  20:00:38 +0000 (0:00:00.595)       0:00:16.113 ******
changed: [instance]

TASK [repo_setup : Dump current-podified hash] *********************************
Thursday 02 October 2025  20:00:38 +0000 (0:00:00.506)       0:00:16.619 ******
skipping: [instance]

TASK [repo_setup : Slurp current podified hash] ********************************
Thursday 02 October 2025  20:00:38 +0000 (0:00:00.039)       0:00:16.659 ******
skipping: [instance]

TASK [repo_setup : Update the value of full_hash] ******************************
Thursday 02 October 2025  20:00:38 +0000 (0:00:00.036)       0:00:16.696 ******
skipping: [instance]

TASK [repo_setup : Export hashes facts for further use] ************************
Thursday 02 October 2025  20:00:38 +0000 (0:00:00.036)       0:00:16.733 ******
ok: [instance]

TASK [repo_setup : Create download directory] **********************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.045)       0:00:16.778 ******
skipping: [instance]

TASK [repo_setup : Print the URL to request] ***********************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.035)       0:00:16.814 ******
skipping: [instance]

TASK [Download the RPM] ********************************************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.038)       0:00:16.852 ******
skipping: [instance]

TASK [repo_setup : Install RHOS Release tool] **********************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.038)       0:00:16.891 ******
skipping: [instance]

TASK [repo_setup : Get rhos-release tool version] ******************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.037)       0:00:16.928 ******
skipping: [instance]

TASK [repo_setup : Print rhos-release tool version] ****************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.035)       0:00:16.963 ******
skipping: [instance]

TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.042)       0:00:17.005 ******
skipping: [instance]

TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.033)       0:00:17.039 ******
ok: [instance]

TASK [repo_setup : Use RDO proxy mirrors] **************************************
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.220)       0:00:17.259 ******
changed: [instance]

TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
Thursday 02 October 2025  20:00:39 +0000 (0:00:00.272)       0:00:17.532 ******
changed: [instance]

TASK [repo_setup : Check for gating.repo file on content provider] *************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.273)       0:00:17.806 ******
skipping: [instance]

TASK [repo_setup : Populate gating repo from content provider ip] **************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.029)       0:00:17.835 ******
skipping: [instance]

TASK [repo_setup : Check for DLRN repo at the destination] *********************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.029)       0:00:17.865 ******
skipping: [instance]

TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.029)       0:00:17.894 ******
skipping: [instance]

TASK [repo_setup : Check for DLRN component repo] ******************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.029)       0:00:17.924 ******
skipping: [instance]

TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.028)       0:00:17.953 ******
skipping: [instance]

TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.028)       0:00:17.981 ******
skipping: [instance]

TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.020)       0:00:18.002 ******
skipping: [instance]

TASK [repo_setup : Cleanup existing metadata] **********************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.036)       0:00:18.039 ******
skipping: [instance]

TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.020)       0:00:18.060 ******
skipping: [instance]

TASK [test_deps : Look for redhat-release rpm] *********************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.023)       0:00:18.084 ******
skipping: [instance]

TASK [test_deps : Remove redhat-release] ***************************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.033)       0:00:18.117 ******
skipping: [instance]

TASK [test_deps : Install centos-stream-release] *******************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.038)       0:00:18.155 ******
skipping: [instance]

TASK [test_deps : Install additional packages] *********************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.035)       0:00:18.190 ******
skipping: [instance]

TASK [test_deps : Install selinux python libs] *********************************
Thursday 02 October 2025  20:00:40 +0000 (0:00:00.037)       0:00:18.228 ******
ok: [instance]

TASK [test_deps : Install python yaml libs] ************************************
Thursday 02 October 2025  20:01:32 +0000 (0:00:51.981)       0:01:10.210 ******
ok: [instance]

TASK [test_deps : Install extra packages] **************************************
Thursday 02 October 2025  20:01:33 +0000 (0:00:01.264)       0:01:11.474 ******
skipping: [instance]

TASK [Ensure CRC is started] ***************************************************
Thursday 02 October 2025  20:01:33 +0000 (0:00:00.035)       0:01:11.510 ******
changed: [instance]

TASK [Inject crc hostname/IP in hosts] *****************************************
Thursday 02 October 2025  20:04:17 +0000 (0:02:43.427)       0:03:54.937 ******
changed: [instance]

PLAY RECAP *********************************************************************
instance                   : ok=21   changed=11   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0

Thursday 02 October 2025  20:04:17 +0000 (0:00:00.334)       0:03:55.272 ******
===============================================================================
Ensure CRC is started ------------------------------------------------- 163.43s
test_deps : Install selinux python libs -------------------------------- 51.98s
repo_setup : Initialize python venv and install requirements ------------ 8.45s
repo_setup : Get repo-setup repository ---------------------------------- 1.28s
test_deps : Install python yaml libs ------------------------------------ 1.26s
repo_setup : Run repo-setup --------------------------------------------- 0.90s
repo_setup : Make sure git-core package is installed -------------------- 0.88s
Gathering Facts --------------------------------------------------------- 0.88s
repo_setup : Install repo-setup package --------------------------------- 0.82s
test_deps : Disable ubi 9 repos ----------------------------------------- 0.75s
repo_setup : Ensure directories are present ----------------------------- 0.62s
repo_setup : Run repo-setup-get-hash ------------------------------------ 0.60s
repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.51s
Inject crc hostname/IP in hosts ----------------------------------------- 0.33s
test_deps : Disable ubi host subscription-manager integration ----------- 0.32s
test_deps : Detect mirrors file ----------------------------------------- 0.29s
repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.27s
repo_setup : Use RDO proxy mirrors -------------------------------------- 0.27s
repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.22s
Deploy repo-setup ------------------------------------------------------- 0.06s

PLAY [Converge] ****************************************************************

TASK [Gathering Facts] *********************************************************
Thursday 02 October 2025  20:04:18 +0000 (0:00:00.016)       0:00:00.016 ******
ok: [instance]

TASK [Load networking_definition] **********************************************
Thursday 02 October 2025  20:04:18 +0000 (0:00:00.866)       0:00:00.882 ******
ok: [instance]

TASK [Check if new ssh keypair exists] *****************************************
Thursday 02 October 2025  20:04:18 +0000 (0:00:00.020)       0:00:00.902 ******

TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
Thursday 02 October 2025  20:04:18 +0000 (0:00:00.023)       0:00:00.926 ******
ok: [instance]

TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.290)       0:00:01.216 ******
ok: [instance]

TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.020)       0:00:01.237 ******
skipping: [instance]

TASK [Add the crc host dynamically] ********************************************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.021)       0:00:01.259 ******
changed: [instance]

TASK [Add ansible_host entry to "controller-0"] ********************************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.021)       0:00:01.280 ******
changed: [instance]

TASK [Add host key to controller-0] ********************************************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.025)       0:00:01.306 ******
changed: [instance]

TASK [libvirt_manager : Ensure output directory exists] ************************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.330)       0:00:01.637 ******
ok: [instance]

TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
Thursday 02 October 2025  20:04:19 +0000 (0:00:00.300)       0:00:01.937 ******
changed: [instance]

TASK [libvirt_manager : Check if KVM is enabled] *******************************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.183)       0:00:02.121 ******
ok: [instance]

TASK [libvirt_manager : Fail if KVM not enabled] *******************************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.182)       0:00:02.304 ******
skipping: [instance]

TASK [libvirt_manager : Check if VMX virtualization] ***************************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.028)       0:00:02.332 ******
skipping: [instance]

TASK [libvirt_manager : Check if SVM virtualization] ***************************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.017)       0:00:02.350 ******
ok: [instance]

TASK [libvirt_manager : Enable VMX virtualization] *****************************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.019)       0:00:02.369 ******
skipping: [instance]

TASK [libvirt_manager : Install packages required for using KVM] ***************
Thursday 02 October 2025  20:04:20 +0000 (0:00:00.029)       0:00:02.399 ******
changed: [instance]

TASK [libvirt_manager : Create rules.d polkit folder] **************************
Thursday 02 October 2025  20:04:31 +0000 (0:00:11.036)       0:00:13.435 ******
changed: [instance]

TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
Thursday 02 October 2025  20:04:31 +0000 (0:00:00.215)       0:00:13.651 ******
changed: [instance]

TASK [libvirt_manager : Restart service polkit service] ************************
Thursday 02 October 2025  20:04:32 +0000 (0:00:00.486)       0:00:14.138 ******
changed: [instance]

TASK [libvirt_manager : Remove directory for service override] *****************
Thursday 02 October 2025  20:04:32 +0000 (0:00:00.587)       0:00:14.725 ******
ok: [instance]

TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
Thursday 02 October 2025  20:04:32 +0000 (0:00:00.197)       0:00:14.922 ******
ok: [instance]

TASK [libvirt_manager : Ensure firewalld service is up] ************************
Thursday 02 October 2025  20:04:33 +0000 (0:00:00.667)       0:00:15.589 ******
changed: [instance]

TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
Thursday 02 October 2025  20:04:34 +0000 (0:00:00.970)       0:00:16.560 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)

TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
Thursday 02 October 2025  20:04:34 +0000 (0:00:00.082)       0:00:16.643 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
Thursday 02 October 2025  20:04:34 +0000 (0:00:00.335)       0:00:16.979 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
Thursday 02 October 2025  20:04:35 +0000 (0:00:00.340)       0:00:17.319 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
Thursday 02 October 2025  20:04:35 +0000 (0:00:00.351)       0:00:17.670 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
Thursday 02 October 2025  20:04:36 +0000 (0:00:00.356)       0:00:18.027 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
Thursday 02 October 2025  20:04:36 +0000 (0:00:00.364)       0:00:18.391 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
Thursday 02 October 2025  20:04:36 +0000 (0:00:00.321)       0:00:18.713 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
Thursday 02 October 2025  20:04:37 +0000 (0:00:00.322)       0:00:19.035 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
Thursday 02 October 2025  20:04:37 +0000 (0:00:00.328)       0:00:19.363 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
Thursday 02 October 2025  20:04:37 +0000 (0:00:00.321)       0:00:19.684 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
Thursday 02 October 2025  20:04:38 +0000 (0:00:00.330)       0:00:20.015 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
Thursday 02 October 2025  20:04:38 +0000 (0:00:00.323)       0:00:20.338 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
Thursday 02 October 2025  20:04:38 +0000 (0:00:00.325)       0:00:20.663 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
Thursday 02 October 2025  20:04:39 +0000 (0:00:00.334)       0:00:20.998 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
Thursday 02 October 2025  20:04:39 +0000 (0:00:00.335)       0:00:21.333 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
Thursday 02 October 2025  20:04:39 +0000 (0:00:00.334)       0:00:21.668 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
Thursday 02 October 2025  20:04:40 +0000 (0:00:00.338)       0:00:22.007 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
Thursday 02 October 2025  20:04:40 +0000 (0:00:00.348)       0:00:22.355 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
Thursday 02 October 2025  20:04:40 +0000 (0:00:00.321)       0:00:22.677 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
Thursday 02 October 2025  20:04:41 +0000 (0:00:00.347)       0:00:23.024 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
Thursday 02 October 2025  20:04:41 +0000 (0:00:00.330)       0:00:23.355 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
Thursday 02 October 2025  20:04:41 +0000 (0:00:00.356)       0:00:23.711 ******
ok: [instance]

TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
Thursday 02 October 2025  20:04:42 +0000 (0:00:00.351)       0:00:24.063 ******
ok: [instance]

TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
Thursday 02 October 2025  20:04:42 +0000 (0:00:00.365)       0:00:24.429 ******
ok: [instance]

TASK [libvirt_manager : Manage service for older releases] *********************
Thursday 02 October 2025  20:04:42 +0000 (0:00:00.363)       0:00:24.792 ******
skipping: [instance]

TASK [libvirt_manager : Get libvirt group users] *******************************
Thursday 02 October 2025  20:04:42 +0000 (0:00:00.025)       0:00:24.818 ******
ok: [instance]

TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
Thursday 02 October 2025  20:04:43 +0000 (0:00:00.291)       0:00:25.109 ******
ok: [instance]

TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
Thursday 02 October 2025  20:04:43 +0000 (0:00:00.437)       0:00:25.547 ******
changed: [instance]

TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
Thursday 02 October 2025  20:04:43 +0000 (0:00:00.350)       0:00:25.897 ******
[WARNING]: Reset is not implemented for this connection
changed: [instance]

TASK [libvirt_manager : Ensure we reload user env] *****************************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.314)       0:00:26.211 ******

TASK [Create virtual baremetal VMs] ********************************************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.016)       0:00:26.228 ******

TASK [libvirt_manager : Import layout generator if needed] *********************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.067)       0:00:26.296 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance

TASK [libvirt_manager : Chose right parameter for layout definition] ***********
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.029)       0:00:26.326 ******
ok: [instance]

TASK [libvirt_manager : Patch the layout if needed] ****************************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.033)       0:00:26.359 ******
skipping: [instance]

TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.062)       0:00:26.422 ******
changed: [instance]

TASK [libvirt_manager : Enable masquerading for public traffic] ****************
Thursday 02 October 2025  20:04:44 +0000 (0:00:00.446)       0:00:26.869 ******
changed: [instance]

TASK [libvirt_manager : Ensure firewalld is restarts] **************************
Thursday 02 October 2025  20:04:45 +0000 (0:00:00.517)       0:00:27.386 ******

RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
Thursday 02 October 2025  20:04:45 +0000 (0:00:00.010)       0:00:27.397 ******
changed: [instance]

TASK [Deploy virtualbmc] *******************************************************
Thursday 02 October 2025  20:04:46 +0000 (0:00:00.869)       0:00:28.267 ******
skipping: [instance]

TASK [libvirt_manager : Let the project know we have vbmc available] ***********
Thursday 02 October 2025  20:04:46 +0000 (0:00:00.029)       0:00:28.297 ******
skipping: [instance]

TASK [libvirt_manager : Create needed workload directory] **********************
Thursday 02 October 2025  20:04:46 +0000 (0:00:00.029)       0:00:28.327 ******
changed: [instance] => (item=workload)
changed: [instance] => (item=reproducer-inventory)
changed: [instance] => (item=volumes)

TASK [libvirt_manager : Allow QEMU on workload directory] **********************
Thursday 02 October 2025  20:04:46 +0000 (0:00:00.585)       0:00:28.913 ******
changed: [instance] => (item=workload)
changed: [instance] => (item=volumes)

TASK [libvirt_manager : Generate networking data] ******************************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.404)       0:00:29.317 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance

TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.080)       0:00:29.398 ******
ok: [instance]

TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.017)       0:00:29.416 ******
ok: [instance]

TASK [libvirt_manager : Load file if exists] ***********************************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.187)       0:00:29.604 ******
skipping: [instance]

TASK [libvirt_manager : Update fact with existing content] *********************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.028)       0:00:29.632 ******
skipping: [instance]

TASK [libvirt_manager : Generate VM list] **************************************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.028)       0:00:29.661 ******
ok: [instance]

TASK [libvirt_manager : Generate/update mapping all nodes] *********************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.054)       0:00:29.716 ******
ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
ok: [instance] => (item={'key': 'compute-1', 'value': 'compute'})

TASK [libvirt_manager : Append baremetal nodes if needed] **********************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.095)       0:00:29.811 ******
skipping: [instance]

TASK [libvirt_manager : Dump MAC mapping] **************************************
Thursday 02 October 2025  20:04:47 +0000 (0:00:00.033)       0:00:29.844 ******
changed: [instance]

TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.370)       0:00:30.215 ******
changed: [instance] => (item=Adding compute-0 to computes)
changed: [instance] => (item=Adding compute-1 to computes)

TASK [networking_mapper : Check for Networking Definition file existence] ******
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.102)       0:00:30.318 ******
skipping: [instance]

TASK [networking_mapper : Load the Networking Definition from file] ************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.025)       0:00:30.343 ******
skipping: [instance]

TASK [networking_mapper : Check for interfaces info file existence] ************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.025)       0:00:30.368 ******
skipping: [instance]

TASK [networking_mapper : Load the interfaces info from file] ******************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.027)       0:00:30.396 ******
skipping: [instance]

TASK [networking_mapper : Ensure local fact is empty] **************************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.026)       0:00:30.422 ******
ok: [instance]

TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.020)       0:00:30.443 ******
ok: [instance] => (item={'networks': {'ctlplane': {'network': '192.168.122.0/24', 'gateway': '192.168.122.1', 'dns': ['192.168.122.253', '192.168.122.254'], 'search-domain': 'ctlplane.example.local', 'mtu': 1500}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}}}}})

TASK [networking_mapper : Gather facts if requested] ***************************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.079)       0:00:30.522 ******
skipping: [instance]

TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.021)       0:00:30.543 ******
changed: [instance]

TASK [networking_mapper : Write the Networking Definition to file] *************
Thursday 02 October 2025  20:04:48 +0000 (0:00:00.235)       0:00:30.778 ******
changed: [instance]

TASK [networking_mapper : Call the networking mapper] **************************
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.464)       0:00:31.243 ******
ok: [instance]

TASK [networking_mapper : Set networking mapper facts] *************************
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.059)       0:00:31.302 ******
ok: [instance]

TASK [networking_mapper : Write the Networking Environment Definition to file] ***
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.046)       0:00:31.349 ******
changed: [instance]

TASK [libvirt_manager : Manage networks if needed] *****************************
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.437)       0:00:31.786 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance

TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.084)       0:00:31.870 ******
ok: [instance] => (item=public)

TASK [libvirt_manager : Ensure networks are defined] ***************************
Thursday 02 October 2025  20:04:49 +0000 (0:00:00.045)       0:00:31.916 ******
changed: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Ensure networks are created/started] *******************
Thursday 02 October 2025  20:04:50 +0000 (0:00:00.383)       0:00:32.299 ******
ok: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Ensure networks are active] ****************************
Thursday 02 October 2025  20:04:50 +0000 (0:00:00.383)       0:00:32.683 ******
ok: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
Thursday 02 October 2025  20:04:50 +0000 (0:00:00.258)       0:00:32.941 ******
changed: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.256)       0:00:33.198 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks_dummy_interfaces.yml for instance

TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.066)       0:00:33.265 ******
ok: [instance]

TASK [libvirt_manager : Fetch bridges ports link info] *************************
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.218)       0:00:33.483 ******
ok: [instance] => (item=cifmw-public)

TASK [Create dummy interfaces to ensure bridges are UP] ************************
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.247)       0:00:33.730 ******

TASK [ci_nmstate : Ensure we have needed facts] ********************************
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.080)       0:00:33.810 ******
skipping: [instance]

TASK [ci_nmstate : Install required packages on instance] **********************
Thursday 02 October 2025  20:04:51 +0000 (0:00:00.041)       0:00:33.851 ******
changed: [instance]

TASK [ci_nmstate : Create the target NMstate dump directory] *******************
Thursday 02 October 2025  20:04:56 +0000 (0:00:04.845)       0:00:38.697 ******
changed: [instance]

TASK [ci_nmstate : Save nmstate state for instance] ****************************
Thursday 02 October 2025  20:04:56 +0000 (0:00:00.236)       0:00:38.933 ******
changed: [instance]

TASK [ci_nmstate : Apply the desidered state on instance] **********************
Thursday 02 October 2025  20:04:57 +0000 (0:00:00.432)       0:00:39.365 ******
changed: [instance]

TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
Thursday 02 October 2025  20:04:58 +0000 (0:00:01.016)       0:00:40.382 ******
changed: [instance]

TASK [Create extra network configuration] **************************************
Thursday 02 October 2025  20:04:58 +0000 (0:00:00.409)       0:00:40.791 ******
skipping: [instance]

TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
Thursday 02 October 2025  20:04:58 +0000 (0:00:00.038)       0:00:40.830 ******
skipping: [instance]

TASK [libvirt_manager : Refresh networking facts on host] **********************
Thursday 02 October 2025  20:04:58 +0000 (0:00:00.033)       0:00:40.863 ******
ok: [instance]

TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
Thursday 02 October 2025  20:04:59 +0000 (0:00:00.502)       0:00:41.366 ******
ok: [instance] => (item=cifmw-public)

TASK [dnsmasq : Install needed packages] ***************************************
Thursday 02 October 2025  20:04:59 +0000 (0:00:00.136)       0:00:41.502 ******
ok: [instance]

TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
Thursday 02 October 2025  20:05:00 +0000 (0:00:01.430)       0:00:42.932 ******
changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})

TASK [dnsmasq : Manage configuration directory] ********************************
Thursday 02 October 2025  20:05:05 +0000 (0:00:04.537)       0:00:47.470 ******
changed: [instance]

TASK [dnsmasq : Manage systemd unit file] **************************************
Thursday 02 October 2025  20:05:05 +0000 (0:00:00.254)       0:00:47.724 ******
changed: [instance]

TASK [dnsmasq : Manage base configuration file] ********************************
Thursday 02 October 2025  20:05:06 +0000 (0:00:00.412)       0:00:48.137 ******
changed: [instance]

TASK [dnsmasq : Render listener configuration] *********************************
Thursday 02 October 2025  20:05:06 +0000 (0:00:00.437)       0:00:48.574 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance

TASK [dnsmasq : Create listener configuration file] ****************************
Thursday 02 October 2025  20:05:06 +0000 (0:00:00.037)       0:00:48.612 ******
changed: [instance]

TASK [dnsmasq : Remove listener configuration file] ****************************
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.453)       0:00:49.066 ******
skipping: [instance]

TASK [dnsmasq : Render dns configuration] **************************************
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.025)       0:00:49.092 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance

TASK [dnsmasq : Create dns configuration file] *********************************
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.037)       0:00:49.129 ******
changed: [instance]

TASK [dnsmasq : Remove dns configuration file] *********************************
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.437)       0:00:49.567 ******
skipping: [instance]

TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.022)       0:00:49.590 ******
ok: [instance] => (item=127.0.0.2)

TASK [dnsmasq : Enable and start service] **************************************
Thursday 02 October 2025  20:05:07 +0000 (0:00:00.255)       0:00:49.845 ******
changed: [instance]

TASK [dnsmasq : Stop service] **************************************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.831)       0:00:50.677 ******
skipping: [instance]

TASK [dnsmasq : Remove unit file] **********************************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.022)       0:00:50.699 ******
skipping: [instance]

TASK [dnsmasq : Remove main configuration files] *******************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.021)       0:00:50.721 ******
skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
skipping: [instance]

TASK [Create dnsmasq networks] *************************************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.032)       0:00:50.754 ******

TASK [dnsmasq : Assert mandatory parameter] ************************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.087)       0:00:50.842 ******
ok: [instance] => changed=false
  msg: All assertions passed

TASK [dnsmasq : Assert mandatory parameters for new network] *******************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.034)       0:00:50.876 ******
ok: [instance] => changed=false
  msg: All assertions passed

TASK [dnsmasq : Create network] ************************************************
Thursday 02 October 2025  20:05:08 +0000 (0:00:00.043)       0:00:50.920 ******
changed: [instance]

TASK [dnsmasq : Remove network] ************************************************
Thursday 02 October 2025  20:05:09 +0000 (0:00:00.536)       0:00:51.456 ******
skipping: [instance]

TASK [dnsmasq : Remove dhcp host files] ****************************************
Thursday 02 October 2025  20:05:09 +0000 (0:00:00.026)       0:00:51.483 ******
skipping: [instance]

TASK [libvirt_manager : Ensure network is in correct zone] *********************
Thursday 02 October 2025  20:05:09 +0000 (0:00:00.027)       0:00:51.511 ******
changed: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Extract IP address from network bridges] ***************
Thursday 02 October 2025  20:05:09 +0000 (0:00:00.353)       0:00:51.865 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/network_bridge_info_gen.yml for instance => (item=cifmw-public)

TASK [libvirt_manager : Extract IP address from network bridges] ***************
Thursday 02 October 2025  20:05:09 +0000 (0:00:00.042)       0:00:51.907 ******
ok: [instance]

TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
Thursday 02 October 2025  20:05:10 +0000 (0:00:00.356)       0:00:52.264 ******
ok: [instance]

TASK [libvirt_manager : Output _network_data] **********************************
Thursday 02 October 2025  20:05:10 +0000 (0:00:00.040)       0:00:52.305 ******
changed: [instance]

TASK [libvirt_manager : Output pub_net] ****************************************
Thursday 02 October 2025  20:05:10 +0000 (0:00:00.405)       0:00:52.710 ******
changed: [instance]

TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
Thursday 02 October 2025  20:05:11 +0000 (0:00:00.429)       0:00:53.140 ******
changed: [instance]

TASK [libvirt_manager : Expose patch for networking_mapper] ********************
Thursday 02 October 2025  20:05:11 +0000 (0:00:00.436)       0:00:53.577 ******
ok: [instance]

TASK [libvirt_manager : Save networking_mapper patch] **************************
Thursday 02 October 2025  20:05:11 +0000 (0:00:00.117)       0:00:53.694 ******
changed: [instance]

TASK [networking_mapper : Check for Networking Definition file existence] ******
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.442)       0:00:54.137 ******
skipping: [instance]

TASK [networking_mapper : Load the Networking Definition from file] ************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.033)       0:00:54.171 ******
skipping: [instance]

TASK [networking_mapper : Check for interfaces info file existence] ************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.040)       0:00:54.211 ******
skipping: [instance]

TASK [networking_mapper : Load the interfaces info from file] ******************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.030)       0:00:54.242 ******
skipping: [instance]

TASK [networking_mapper : Ensure local fact is empty] **************************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.031)       0:00:54.273 ******
ok: [instance]

TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.022)       0:00:54.296 ******
ok: [instance] => (item={'networks': {'ctlplane': {'network': '192.168.122.0/24', 'gateway': '192.168.122.1', 'dns': ['192.168.122.253', '192.168.122.254'], 'search-domain': 'ctlplane.example.local', 'mtu': 1500}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}}}}})
ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.100.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})

TASK [networking_mapper : Gather facts if requested] ***************************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.092)       0:00:54.389 ******
skipping: [instance]

TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.022)       0:00:54.411 ******
ok: [instance]

TASK [networking_mapper : Write the Networking Definition to file] *************
Thursday 02 October 2025  20:05:12 +0000 (0:00:00.285)       0:00:54.696 ******
changed: [instance]

TASK [networking_mapper : Call the networking mapper] **************************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.521)       0:00:55.218 ******
ok: [instance]

TASK [networking_mapper : Set networking mapper facts] *************************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.067)       0:00:55.286 ******
ok: [instance]

TASK [networking_mapper : Write the Networking Environment Definition to file] ***
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.032)       0:00:55.319 ******
changed: [instance]

TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.495)       0:00:55.814 ******
ok: [instance]

TASK [libvirt_manager : Unset patch] *******************************************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.035)       0:00:55.850 ******
ok: [instance]

TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.030)       0:00:55.881 ******
ok: [instance]

TASK [libvirt_manager : Reserve IPs on networks] *******************************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.027)       0:00:55.908 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=ctlplane)
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=public)

TASK [libvirt_manager : Loop on host IPs] **************************************
Thursday 02 October 2025  20:05:13 +0000 (0:00:00.051)       0:00:55.960 ******
skipping: [instance] => (item=compute-0 - ctlplane)
skipping: [instance] => (item=compute-1 - ctlplane)
skipping: [instance]

TASK [libvirt_manager : Loop on host IPs] **************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.098)       0:00:56.058 ******
ok: [instance] => (item=compute-0 - public)
ok: [instance] => (item=compute-1 - public)

TASK [Inject DHCP entries for net {{ net_name }}] ******************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.135)       0:00:56.193 ******

TASK [dnsmasq : Ensure we have the right data and type] ************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.072)       0:00:56.265 ******
ok: [instance]

TASK [dnsmasq : Assert we have needed host data] *******************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.059)       0:00:56.324 ******
ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:3d:18:b7', 'ips': ['192.168.100.10', '']})
ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:8b:03:d2', 'ips': ['192.168.100.11', '']})

TASK [dnsmasq : Ensure networks exists] ****************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.069)       0:00:56.394 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/_check_net_status.yml for instance => (item=public)

TASK [dnsmasq : Check network file status] *************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.059)       0:00:56.453 ******
ok: [instance]

TASK [dnsmasq : Assert network exists] *****************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.242)       0:00:56.695 ******
ok: [instance]

TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.041)       0:00:56.737 ******
ok: [instance]

TASK [dnsmasq : Compute entry] *************************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.025)       0:00:56.762 ******
ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:3d:18:b7', 'ips': ['192.168.100.10', '']})
ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:8b:03:d2', 'ips': ['192.168.100.11', '']})

TASK [dnsmasq : Create add/remove sets] ****************************************
Thursday 02 October 2025  20:05:14 +0000 (0:00:00.178)       0:00:56.940 ******
ok: [instance]

TASK [dnsmasq : Add DHCP entries] **********************************************
Thursday 02 October 2025  20:05:15 +0000 (0:00:00.049)       0:00:56.990 ******
changed: [instance] => (item={'file': 'public_compute-0_52:54:00:3d:18:b7', 'entry': '52:54:00:3d:18:b7,192.168.100.10,compute-0', 'state': 'present'})
changed: [instance] => (item={'file': 'public_compute-1_52:54:01:8b:03:d2', 'entry': '52:54:01:8b:03:d2,192.168.100.11,compute-1', 'state': 'present'})

TASK [dnsmasq : Remove DHCP entries] *******************************************
Thursday 02 October 2025  20:05:15 +0000 (0:00:00.916)       0:00:57.906 ******
skipping: [instance]

TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
Thursday 02 October 2025  20:05:15 +0000 (0:00:00.025)       0:00:57.932 ******
ok: [instance] => (item=compute-0)
ok: [instance] => (item=compute-1)

TASK [Inject VMs in the .utility zone] *****************************************
Thursday 02 October 2025  20:05:16 +0000 (0:00:00.176)       0:00:58.109 ******

TASK [dnsmasq : Assert we have needed host record data] ************************
Thursday 02 October 2025  20:05:16 +0000 (0:00:00.097)       0:00:58.206 ******
ok: [instance]

TASK [dnsmasq : Assert each address element have needed data] ******************
Thursday 02 October 2025  20:05:16 +0000 (0:00:00.059)       0:00:58.265 ******
ok: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
ok: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
ok: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
ok: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})

TASK [dnsmasq : Add/Remove address] ********************************************
Thursday 02 October 2025  20:05:16 +0000 (0:00:00.169)       0:00:58.434 ******
changed: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
changed: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
changed: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
changed: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})

TASK [libvirt_manager : Ensure some domains are local] *************************
Thursday 02 October 2025  20:05:17 +0000 (0:00:01.505)       0:00:59.940 ******
changed: [instance]

TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
Thursday 02 October 2025  20:05:18 +0000 (0:00:00.422)       0:01:00.362 ******

RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
Thursday 02 October 2025  20:05:18 +0000 (0:00:00.011)       0:01:00.373 ******
changed: [instance]

RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
Thursday 02 October 2025  20:05:19 +0000 (0:00:00.904)       0:01:01.278 ******
changed: [instance]

RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
Thursday 02 October 2025  20:05:19 +0000 (0:00:00.388)       0:01:01.666 ******
changed: [instance]

TASK [libvirt_manager : Create group inventories] ******************************
Thursday 02 October 2025  20:05:20 +0000 (0:00:00.372)       0:01:02.038 ******
changed: [instance] => (item=compute)

TASK [libvirt_manager : Create "all" group inventory file] *********************
Thursday 02 October 2025  20:05:20 +0000 (0:00:00.466)       0:01:02.505 ******
changed: [instance]

TASK [libvirt_manager : Ensure storage pool is present.] ***********************
Thursday 02 October 2025  20:05:20 +0000 (0:00:00.447)       0:01:02.953 ******
skipping: [instance]

TASK [libvirt_manager : Ensure images are present] *****************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.041)       0:01:02.994 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/get_image.yml for instance => (item=compute)

TASK [libvirt_manager : Ensure directory exists] *******************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.091)       0:01:03.086 ******
skipping: [instance]

TASK [libvirt_manager : Check if base image exists] ****************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.022)       0:01:03.109 ******
skipping: [instance]

TASK [libvirt_manager : Download base image] ***********************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.021)       0:01:03.130 ******
skipping: [instance]

TASK [libvirt_manager : Check image] *******************************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.021)       0:01:03.151 ******
skipping: [instance]

TASK [libvirt_manager : Assert image status] ***********************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.020)       0:01:03.171 ******
skipping: [instance]

TASK [libvirt_manager : Ensure image access rights] ****************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.020)       0:01:03.192 ******
skipping: [instance]

TASK [libvirt_manager : Get ssh key state] *************************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.022)       0:01:03.214 ******
ok: [instance]

TASK [libvirt_manager : Create temporary ssh keypair] **************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.193)       0:01:03.407 ******
changed: [instance]

TASK [libvirt_manager : Slurp public key for later use] ************************
Thursday 02 October 2025  20:05:21 +0000 (0:00:00.437)       0:01:03.845 ******
ok: [instance]

TASK [libvirt_manager : Slurp private key for later use] ***********************
Thursday 02 October 2025  20:05:22 +0000 (0:00:00.308)       0:01:04.154 ******
ok: [instance]

TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
Thursday 02 October 2025  20:05:22 +0000 (0:00:00.192)       0:01:04.347 ******
changed: [instance]

TASK [libvirt_manager : Create fact holding network data for VMs] **************
Thursday 02 October 2025  20:05:22 +0000 (0:00:00.448)       0:01:04.795 ******
ok: [instance]

TASK [libvirt_manager : List existing networks] ********************************
Thursday 02 October 2025  20:05:22 +0000 (0:00:00.024)       0:01:04.819 ******
ok: [instance]

TASK [libvirt_manager : Gather pool fact] **************************************
Thursday 02 October 2025  20:05:23 +0000 (0:00:00.263)       0:01:05.083 ******
ok: [instance]

TASK [libvirt_manager : Create and run VMs] ************************************
Thursday 02 October 2025  20:05:23 +0000 (0:00:00.396)       0:01:05.479 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_vms.yml for instance => (item={'key': 'compute-0', 'value': 'compute'})
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_vms.yml for instance => (item={'key': 'compute-1', 'value': 'compute'})

TASK [libvirt_manager : Create VM image for compute-0] *************************
Thursday 02 October 2025  20:05:23 +0000 (0:00:00.099)       0:01:05.579 ******
changed: [instance]

TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
Thursday 02 October 2025  20:05:23 +0000 (0:00:00.392)       0:01:05.971 ******
changed: [instance]

TASK [libvirt_manager : Define VMs for type compute-0] *************************
Thursday 02 October 2025  20:05:24 +0000 (0:00:00.276)       0:01:06.248 ******
changed: [instance]

TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
Thursday 02 October 2025  20:05:24 +0000 (0:00:00.441)       0:01:06.689 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance

TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
Thursday 02 October 2025  20:05:24 +0000 (0:00:00.030)       0:01:06.719 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)

TASK [libvirt_manager : Get virtual network information] ***********************
Thursday 02 October 2025  20:05:24 +0000 (0:00:00.042)       0:01:06.761 ******
ok: [instance]

TASK [libvirt_manager : Create network to bridge mapping] **********************
Thursday 02 October 2025  20:05:25 +0000 (0:00:00.277)       0:01:07.039 ******
ok: [instance] => (item=default)
ok: [instance] => (item=crc)
ok: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Dump domain xml] ***************************************
Thursday 02 October 2025  20:05:25 +0000 (0:00:00.059)       0:01:07.099 ******
ok: [instance]

TASK [libvirt_manager : Extract networks from XML] *****************************
Thursday 02 October 2025  20:05:25 +0000 (0:00:00.281)       0:01:07.380 ******
ok: [instance]

TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
Thursday 02 October 2025  20:05:25 +0000 (0:00:00.229)       0:01:07.610 ******
changed: [instance]

TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
Thursday 02 October 2025  20:05:25 +0000 (0:00:00.356)       0:01:07.966 ******
skipping: [instance]

TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.024)       0:01:07.990 ******
skipping: [instance]

TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.035)       0:01:08.026 ******
skipping: [instance]

TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.032)       0:01:08.058 ******
skipping: [instance]

TASK [libvirt_manager : Get VM UUID] *******************************************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.035)       0:01:08.093 ******
changed: [instance]

TASK [libvirt_manager : Inject UUID in dataset] ********************************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.267)       0:01:08.361 ******
ok: [instance]

TASK [libvirt_manager : Create cloud-init ISO] *********************************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.048)       0:01:08.410 ******
skipping: [instance]

TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.027)       0:01:08.438 ******
skipping: [instance]

TASK [libvirt_manager : Attach additional devices if specified] ****************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.025)       0:01:08.463 ******
skipping: [instance]

TASK [libvirt_manager : Create VM image for compute-1] *************************
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.059)       0:01:08.523 ******
changed: [instance]

TASK [libvirt_manager : Ensure file ownership and rights for compute-1] ********
Thursday 02 October 2025  20:05:26 +0000 (0:00:00.305)       0:01:08.828 ******
changed: [instance]

TASK [libvirt_manager : Define VMs for type compute-1] *************************
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.284)       0:01:09.112 ******
changed: [instance]

TASK [libvirt_manager : Attach listed networks to the VMs compute-1] ***********
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.341)       0:01:09.453 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance

TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.032)       0:01:09.485 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)

TASK [libvirt_manager : Get virtual network information] ***********************
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.041)       0:01:09.527 ******
ok: [instance]

TASK [libvirt_manager : Create network to bridge mapping] **********************
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.268)       0:01:09.796 ******
ok: [instance] => (item=default)
ok: [instance] => (item=crc)
ok: [instance] => (item=cifmw-public)

TASK [libvirt_manager : Dump domain xml] ***************************************
Thursday 02 October 2025  20:05:27 +0000 (0:00:00.054)       0:01:09.851 ******
ok: [instance]

TASK [libvirt_manager : Extract networks from XML] *****************************
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.259)       0:01:10.110 ******
ok: [instance]

TASK [libvirt_manager : Attach interface public on cifmw-compute-1] ************
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.250)       0:01:10.361 ******
changed: [instance]

TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-1] *****
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.354)       0:01:10.716 ******
skipping: [instance]

TASK [libvirt_manager : Create the requested extra disks for compute-1] ********
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.023)       0:01:10.739 ******
skipping: [instance]

TASK [libvirt_manager : Find volume attachments for VM compute-1] **************
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.031)       0:01:10.771 ******
skipping: [instance]

TASK [libvirt_manager : Attach volumes for VM compute-1] ***********************
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.033)       0:01:10.805 ******
skipping: [instance]

TASK [libvirt_manager : Get VM UUID] *******************************************
Thursday 02 October 2025  20:05:28 +0000 (0:00:00.030)       0:01:10.835 ******
changed: [instance]

TASK [libvirt_manager : Inject UUID in dataset] ********************************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.277)       0:01:11.112 ******
ok: [instance]

TASK [libvirt_manager : Create cloud-init ISO] *********************************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.042)       0:01:11.154 ******
skipping: [instance]

TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.024)       0:01:11.178 ******
skipping: [instance]

TASK [libvirt_manager : Attach additional devices if specified] ****************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.023)       0:01:11.202 ******
skipping: [instance]

TASK [libvirt_manager : Start (power-on) VMs] **********************************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.050)       0:01:11.252 ******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance

TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.046)       0:01:11.299 ******
ok: [instance] => (item=crc)

TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
Thursday 02 October 2025  20:05:29 +0000 (0:00:00.289)       0:01:11.588 ******
skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
skipping: [instance]

TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
Thursday 02 October 2025  20:05:30 +0000 (0:00:01.053)       0:01:12.642 ******
skipping: [instance] => (item=compute-0.utility)
skipping: [instance] => (item=compute-1.utility)
skipping: [instance]

TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
Thursday 02 October 2025  20:05:30 +0000 (0:00:00.119)       0:01:12.762 ******
skipping: [instance] => (item={'changed': False, 'skipped': True, 'skip_reason': 'Conditional result was False', 'false_condition': "vm_data.disk_file_name != 'blank'", '_vm': {'key': 'compute-0', 'value': 'compute'}, 'ansible_loop_var': '_vm'})
skipping: [instance] => (item={'changed': False, 'skipped': True, 'skip_reason': 'Conditional result was False', 'false_condition': "vm_data.disk_file_name != 'blank'", '_vm': {'key': 'compute-1', 'value': 'compute'}, 'ansible_loop_var': '_vm'})
skipping: [instance]

TASK [libvirt_manager : Configure managed VMs] *********************************
Thursday 02 October 2025  20:05:30 +0000 (0:00:00.036)       0:01:12.799 ******
skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
skipping: [instance]

TASK [Create VBMC entity] ******************************************************
Thursday 02 October 2025  20:05:30 +0000 (0:00:00.053)       0:01:12.853 ******
skipping: [instance] => (item=compute-0)
skipping: [instance] => (item=compute-1)
skipping: [instance]

TASK [libvirt_manager : List running virtual machines.] ************************
Thursday 02 October 2025  20:05:30 +0000 (0:00:00.049)       0:01:12.902 ******
ok: [instance]

TASK [libvirt_manager : Dump UUIDs] ********************************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.268)       0:01:13.171 ******
changed: [instance]

TASK [Ensure fresh vbmc listing] ***********************************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.419)       0:01:13.591 ******
skipping: [instance]

TASK [libvirt_manager : Update vbmc related fact] ******************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.036)       0:01:13.628 ******
skipping: [instance]

TASK [libvirt_manager : Dump vbmc known hosts] *********************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.036)       0:01:13.665 ******
skipping: [instance]

TASK [libvirt_manager : Copy authorized_keys] **********************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.040)       0:01:13.705 ******
skipping: [instance]

TASK [libvirt_manager : Enable root access on CRC] *****************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.029)       0:01:13.734 ******
skipping: [instance]

TASK [Generate baremetal-info fact] ********************************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.036)       0:01:13.770 ******

TASK [reproducer : Ensure directories exist] ***********************************
Thursday 02 October 2025  20:05:31 +0000 (0:00:00.090)       0:01:13.860 ******
changed: [instance] => (item=parameters)
ok: [instance] => (item=artifacts)

TASK [reproducer : Convert VBMC list into a dict for better usage] *************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.437)       0:01:14.297 ******
skipping: [instance]

TASK [reproducer : Check if baremetal-info.yml exists] *************************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.038)       0:01:14.336 ******
ok: [instance]

TASK [reproducer : Get content of baremetal-info file] *************************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.225)       0:01:14.561 ******
skipping: [instance]

TASK [reproducer : Interpret remote file content as yaml] **********************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.021)       0:01:14.582 ******
skipping: [instance]

TASK [reproducer : Slurp content of: /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.036)       0:01:14.619 ******
skipping: [instance]

TASK [reproducer : Set cifmw_libvirt_manager_mac_map fact from /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.027)       0:01:14.646 ******
skipping: [instance]

TASK [reproducer : Generate libvirt_manager_bm_info_data fact] *****************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.027)       0:01:14.673 ******
ok: [instance] => (item={'key': 'cifmw-compute-0', 'value': 'd441a99a-c1a8-4202-bf66-0d65552e51a4'})
ok: [instance] => (item={'key': 'cifmw-compute-1', 'value': '14763b28-42bb-458c-b987-8d43618ae7a7'})

TASK [reproducer : Output baremetal info file] *********************************
Thursday 02 October 2025  20:05:32 +0000 (0:00:00.082)       0:01:14.756 ******
changed: [instance]

TASK [reproducer : Output ironic_nodes to file] ********************************
Thursday 02 October 2025  20:05:33 +0000 (0:00:00.392)       0:01:15.149 ******
skipping: [instance]

TASK [Run Sushy Emulator role against OCP] *************************************
Thursday 02 October 2025  20:05:33 +0000 (0:00:00.026)       0:01:15.175 ******

TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
Thursday 02 October 2025  20:05:33 +0000 (0:00:00.078)       0:01:15.254 ******
changed: [instance]

TASK [sushy_emulator : Install required packages] ******************************
Thursday 02 October 2025  20:05:33 +0000 (0:00:00.216)       0:01:15.471 ******
changed: [instance]

TASK [sushy_emulator : Get ingresses domain] ***********************************
Thursday 02 October 2025  20:05:38 +0000 (0:00:04.677)       0:01:20.149 ******
changed: [instance]

TASK [sushy_emulator : Set sushy url for ocp installation] *********************
Thursday 02 October 2025  20:05:39 +0000 (0:00:01.215)       0:01:21.364 ******
ok: [instance]

TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
Thursday 02 October 2025  20:05:39 +0000 (0:00:00.026)       0:01:21.391 ******
changed: [instance]

TASK [sushy_emulator : Slurp private ssh key for later use] ********************
Thursday 02 October 2025  20:05:39 +0000 (0:00:00.293)       0:01:21.685 ******
ok: [instance]

TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
Thursday 02 October 2025  20:05:39 +0000 (0:00:00.205)       0:01:21.891 ******
changed: [instance -> controller-0(192.168.25.229)]

TASK [sushy_emulator : Run ssh-keyscan] ****************************************
Thursday 02 October 2025  20:05:41 +0000 (0:00:01.286)       0:01:23.177 ******
changed: [instance]

TASK [sushy_emulator : Write known hosts for later use] ************************
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.261)       0:01:23.439 ******
changed: [instance]

TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.393)       0:01:23.832 ******
skipping: [instance]

TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.031)       0:01:23.864 ******
skipping: [instance]

TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.032)       0:01:23.897 ******
skipping: [instance]

TASK [sushy_emulator : Generate list of filtered VMs] **************************
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.028)       0:01:23.925 ******
ok: [instance]

TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
Thursday 02 October 2025  20:05:41 +0000 (0:00:00.040)       0:01:23.966 ******
skipping: [instance]

TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
Thursday 02 October 2025  20:05:42 +0000 (0:00:00.022)       0:01:23.988 ******
skipping: [instance]

TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
Thursday 02 October 2025  20:05:42 +0000 (0:00:00.020)       0:01:24.009 ******
skipping: [instance]

TASK [sushy_emulator : Generate htpasswd string] *******************************
Thursday 02 October 2025  20:05:42 +0000 (0:00:00.021)       0:01:24.031 ******
changed: [instance]

TASK [sushy_emulator : Write sushy emulator resource loop] *********************
Thursday 02 October 2025  20:05:42 +0000 (0:00:00.222)       0:01:24.253 ******
changed: [instance] => (item=secret)
changed: [instance] => (item=configmap)
changed: [instance] => (item=pod)
changed: [instance] => (item=service)
changed: [instance] => (item=route)

TASK [sushy_emulator : Write sushy emulator config] ****************************
Thursday 02 October 2025  20:05:44 +0000 (0:00:01.881)       0:01:26.134 ******
skipping: [instance]

TASK [sushy_emulator : Write htpasswd string to file] **************************
Thursday 02 October 2025  20:05:44 +0000 (0:00:00.021)       0:01:26.155 ******
skipping: [instance]

TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
Thursday 02 October 2025  20:05:44 +0000 (0:00:00.024)       0:01:26.180 ******
changed: [instance]

TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
Thursday 02 October 2025  20:05:46 +0000 (0:00:02.266)       0:01:28.447 ******
ok: [instance]

TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
Thursday 02 October 2025  20:06:38 +0000 (0:00:51.914)       0:02:20.361 ******
changed: [instance] => (item=secret)
changed: [instance] => (item=configmap)
changed: [instance] => (item=service)
changed: [instance] => (item=route)

TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
Thursday 02 October 2025  20:06:40 +0000 (0:00:02.460)       0:02:22.822 ******
[WARNING]: unknown field "spec.selector"
[WARNING]: unknown field
"spec.containers[0].readinessProbe.httpGet.initialDelaySeconds"
[WARNING]: unknown field
"spec.containers[0].readinessProbe.httpGet.periodSeconds"
[WARNING]: unknown field
"spec.containers[0].livenessProbe.httpGet.initialDelaySeconds"
[WARNING]: unknown field
"spec.containers[0].livenessProbe.httpGet.failureThreshold"
[WARNING]: unknown field
"spec.containers[0].livenessProbe.httpGet.periodSeconds"
[WARNING]: unknown field
"spec.containers[0].startupProbe.httpGet.failureThreshold"
[WARNING]: unknown field
"spec.containers[0].startupProbe.httpGet.initialDelaySeconds"
changed: [instance]

TASK [podman : Ensure podman is installed] *************************************
Thursday 02 October 2025  20:07:51 +0000 (0:01:10.812)       0:03:33.634 ******
skipping: [instance]

TASK [podman : Enable loginctl linger for ansible_user_id] *********************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.021)       0:03:33.656 ******
skipping: [instance]

TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.025)       0:03:33.681 ******
skipping: [instance]

TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.023)       0:03:33.705 ******
skipping: [instance]

TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.021)       0:03:33.727 ******
skipping: [instance]

TASK [sushy_emulator : Pull Sushy Emulator container image] ********************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.026)       0:03:33.753 ******
skipping: [instance]

TASK [sushy_emulator : Create and start Sushy Emulator container] **************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.020)       0:03:33.773 ******
skipping: [instance]

TASK [Verify connection to baremetal VMs via Sushy Emulator] *******************
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.024)       0:03:33.798 ******

TASK [sushy_emulator : Load baremetal hosts from libvirt_manager_bm_info_data fact] ***
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.063)       0:03:33.861 ******
ok: [instance]

TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.031)       0:03:33.893 ******
skipping: [instance]

TASK [sushy_emulator : Set cifmw_baremetal_hosts fact from /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.027)       0:03:33.921 ******
skipping: [instance]

TASK [sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket] ***
Thursday 02 October 2025  20:07:51 +0000 (0:00:00.024)       0:03:33.946 ******
ok: [instance]

TASK [sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator] ***
Thursday 02 October 2025  20:07:53 +0000 (0:00:01.199)       0:03:35.145 ******
ok: [instance] => (item=d441a99a-c1a8-4202-bf66-0d65552e51a4)
ok: [instance] => (item=14763b28-42bb-458c-b987-8d43618ae7a7)

TASK [sushy_emulator : Verify baremetal VM power status] ***********************
Thursday 02 October 2025  20:07:55 +0000 (0:00:02.601)       0:03:37.747 ******
ok: [instance] => (item=cifmw-compute-0)
ok: [instance] => (item=cifmw-compute-1)

TASK [Run Sushy Emulator role against podman] **********************************
Thursday 02 October 2025  20:07:55 +0000 (0:00:00.048)       0:03:37.796 ******

TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
Thursday 02 October 2025  20:07:55 +0000 (0:00:00.088)       0:03:37.884 ******
ok: [instance]

TASK [sushy_emulator : Install required packages] ******************************
Thursday 02 October 2025  20:07:56 +0000 (0:00:00.196)       0:03:38.081 ******
ok: [instance]

TASK [sushy_emulator : Get ingresses domain] ***********************************
Thursday 02 October 2025  20:07:57 +0000 (0:00:01.248)       0:03:39.330 ******
skipping: [instance]

TASK [sushy_emulator : Set sushy url for ocp installation] *********************
Thursday 02 October 2025  20:07:57 +0000 (0:00:00.019)       0:03:39.349 ******
skipping: [instance]

TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
Thursday 02 October 2025  20:07:57 +0000 (0:00:00.019)       0:03:39.368 ******
ok: [instance]

TASK [sushy_emulator : Slurp private ssh key for later use] ********************
Thursday 02 October 2025  20:07:57 +0000 (0:00:00.251)       0:03:39.620 ******
ok: [instance]

TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
Thursday 02 October 2025  20:07:57 +0000 (0:00:00.180)       0:03:39.801 ******
ok: [instance -> controller-0(192.168.25.229)]

TASK [sushy_emulator : Run ssh-keyscan] ****************************************
Thursday 02 October 2025  20:07:58 +0000 (0:00:01.160)       0:03:40.961 ******
changed: [instance]

TASK [sushy_emulator : Write known hosts for later use] ************************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.234)       0:03:41.196 ******
changed: [instance]

TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.356)       0:03:41.552 ******
skipping: [instance]

TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.026)       0:03:41.579 ******
skipping: [instance]

TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.025)       0:03:41.604 ******
skipping: [instance]

TASK [sushy_emulator : Generate list of filtered VMs] **************************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.023)       0:03:41.628 ******
ok: [instance]

TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.036)       0:03:41.664 ******
skipping: [instance]

TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.018)       0:03:41.682 ******
skipping: [instance]

TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.019)       0:03:41.702 ******
skipping: [instance]

TASK [sushy_emulator : Generate htpasswd string] *******************************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.021)       0:03:41.723 ******
changed: [instance]

TASK [sushy_emulator : Write sushy emulator resource loop] *********************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.222)       0:03:41.946 ******
skipping: [instance] => (item=secret)
skipping: [instance] => (item=configmap)
skipping: [instance] => (item=pod)
skipping: [instance] => (item=service)
skipping: [instance] => (item=route)
skipping: [instance]

TASK [sushy_emulator : Write sushy emulator config] ****************************
Thursday 02 October 2025  20:07:59 +0000 (0:00:00.031)       0:03:41.977 ******
changed: [instance]

TASK [sushy_emulator : Write htpasswd string to file] **************************
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.357)       0:03:42.335 ******
changed: [instance]

TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.377)       0:03:42.713 ******
skipping: [instance]

TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.020)       0:03:42.733 ******
skipping: [instance]

TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.019)       0:03:42.752 ******
skipping: [instance] => (item=secret)
skipping: [instance] => (item=configmap)
skipping: [instance] => (item=service)
skipping: [instance] => (item=route)
skipping: [instance]

TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.032)       0:03:42.785 ******
skipping: [instance]

TASK [podman : Ensure podman is installed] *************************************
Thursday 02 October 2025  20:08:00 +0000 (0:00:00.020)       0:03:42.805 ******
ok: [instance]

TASK [podman : Enable loginctl linger for ansible_user_id] *********************
Thursday 02 October 2025  20:08:02 +0000 (0:00:01.248)       0:03:44.053 ******
changed: [instance]

TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
Thursday 02 October 2025  20:08:02 +0000 (0:00:00.213)       0:03:44.267 ******
skipping: [instance]

TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
Thursday 02 October 2025  20:08:02 +0000 (0:00:00.027)       0:03:44.295 ******
skipping: [instance]

TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
Thursday 02 October 2025  20:08:02 +0000 (0:00:00.025)       0:03:44.320 ******
skipping: [instance]

TASK [sushy_emulator : Pull Sushy Emulator container image] ********************
Thursday 02 October 2025  20:08:02 +0000 (0:00:00.029)       0:03:44.350 ******
changed: [instance]

TASK [sushy_emulator : Create and start Sushy Emulator container] **************
Thursday 02 October 2025  20:08:09 +0000 (0:00:06.796)       0:03:51.147 ******
changed: [instance]

TASK [Verify connection to baremetal VMs via Sushy Emulator] *******************
Thursday 02 October 2025  20:08:10 +0000 (0:00:00.860)       0:03:52.007 ******

TASK [sushy_emulator : Load baremetal hosts from libvirt_manager_bm_info_data fact] ***
Thursday 02 October 2025  20:08:10 +0000 (0:00:00.159)       0:03:52.166 ******
ok: [instance]

TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
Thursday 02 October 2025  20:08:10 +0000 (0:00:00.037)       0:03:52.203 ******
skipping: [instance]

TASK [sushy_emulator : Set cifmw_baremetal_hosts fact from /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
Thursday 02 October 2025  20:08:10 +0000 (0:00:00.033)       0:03:52.237 ******
skipping: [instance]

TASK [sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket] ***
Thursday 02 October 2025  20:08:10 +0000 (0:00:00.023)       0:03:52.260 ******
ok: [instance]

TASK [sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator] ***
Thursday 02 October 2025  20:08:11 +0000 (0:00:00.986)       0:03:53.247 ******
ok: [instance] => (item=d441a99a-c1a8-4202-bf66-0d65552e51a4)
ok: [instance] => (item=14763b28-42bb-458c-b987-8d43618ae7a7)

TASK [sushy_emulator : Verify baremetal VM power status] ***********************
Thursday 02 October 2025  20:08:13 +0000 (0:00:02.361)       0:03:55.609 ******
ok: [instance] => (item=cifmw-compute-0)
ok: [instance] => (item=cifmw-compute-1)

PLAY RECAP *********************************************************************
instance                   : ok=228  changed=86   unreachable=0    failed=0    skipped=105  rescued=0    ignored=0

Thursday 02 October 2025  20:08:13 +0000 (0:00:00.062)       0:03:55.671 ******
===============================================================================
sushy_emulator : Apply Sushy Emulator pod resource --------------------- 70.81s
sushy_emulator : Check if router pod is running in openshift-ingress namespace -- 51.91s
libvirt_manager : Install packages required for using KVM -------------- 11.04s
sushy_emulator : Pull Sushy Emulator container image -------------------- 6.80s
ci_nmstate : Install required packages on instance ---------------------- 4.85s
sushy_emulator : Install required packages ------------------------------ 4.68s
dnsmasq : Ensure SELinux knows about the new files and directories ------ 4.54s
sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator --- 2.60s
sushy_emulator : Apply Sushy Emulator resources ------------------------- 2.46s
sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator --- 2.36s
sushy_emulator : Create the sushy-emulator namespace -------------------- 2.27s
sushy_emulator : Write sushy emulator resource loop --------------------- 1.88s
libvirt_manager : Restart firewalld ------------------------------------- 1.77s
dnsmasq : Add/Remove address -------------------------------------------- 1.51s
dnsmasq : Install needed packages --------------------------------------- 1.43s
sushy_emulator : Allow Sushy Emulator key ------------------------------- 1.29s
sushy_emulator : Install required packages ------------------------------ 1.25s
podman : Ensure podman is installed ------------------------------------- 1.25s
sushy_emulator : Get ingresses domain ----------------------------------- 1.22s
sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket --- 1.20s