PLAY [Prepare mock iDRAC server] ***********************************************

TASK [Create mock server directory] ********************************************
Wednesday 11 March 2026  19:11:01 +0000 (0:00:00.024)       0:00:00.024 *******
changed: [instance]

TASK [Generate self-signed TLS certificate] ************************************
Wednesday 11 March 2026  19:11:01 +0000 (0:00:00.353)       0:00:00.378 *******
changed: [instance]

TASK [Copy mock iDRAC server script] *******************************************
Wednesday 11 March 2026  19:11:02 +0000 (0:00:00.418)       0:00:00.797 *******
changed: [instance]

TASK [Start mock iDRAC server] *************************************************
Wednesday 11 March 2026  19:11:02 +0000 (0:00:00.521)       0:00:01.318 *******
changed: [instance]

TASK [Record mock server PID] **************************************************
Wednesday 11 March 2026  19:11:03 +0000 (0:00:00.190)       0:00:01.509 *******
ok: [instance]

TASK [Wait for mock iDRAC to respond] ******************************************
Wednesday 11 March 2026  19:11:03 +0000 (0:00:00.209)       0:00:01.718 *******
ok: [instance]

PLAY RECAP *********************************************************************
instance                   : ok=6    changed=4    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

Wednesday 11 March 2026  19:11:03 +0000 (0:00:00.422)       0:00:02.141 *******
===============================================================================
Copy mock iDRAC server script ------------------------------------------- 0.52s
Wait for mock iDRAC to respond ------------------------------------------ 0.42s
Generate self-signed TLS certificate ------------------------------------ 0.42s
Create mock server directory -------------------------------------------- 0.35s
Record mock server PID -------------------------------------------------- 0.21s
Start mock iDRAC server ------------------------------------------------- 0.19s

PLAY [Converge -- test bm_* Redfish tasks against mock iDRAC] ******************

TASK [Test bm_power_off] *******************************************************
Wednesday 11 March 2026  19:11:04 +0000 (0:00:00.045)       0:00:00.045 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_power_off.yml for instance

TASK [Reset mock to power Off] *************************************************
Wednesday 11 March 2026  19:11:04 +0000 (0:00:00.024)       0:00:00.070 *******
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Wednesday 11 March 2026  19:11:04 +0000 (0:00:00.422)       0:00:00.492 *******

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:04 +0000 (0:00:00.032)       0:00:00.524 *******
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.301)       0:00:00.826 *******
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.021)       0:00:00.848 *******
skipping: [instance]

TASK [Query mock state after power_off (already off)] **************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.023)       0:00:00.872 *******
ok: [instance]

TASK [Assert host is still Off] ************************************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.333)       0:00:01.205 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power On] **************************************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.024)       0:00:01.230 *******
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.300)       0:00:01.531 *******

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:05 +0000 (0:00:00.026)       0:00:01.558 *******
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.283)       0:00:01.841 *******
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.298)       0:00:02.140 *******
ok: [instance]

TASK [Query mock state after power_off (was on)] *******************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.290)       0:00:02.431 *******
ok: [instance]

TASK [Assert host is now Off] **************************************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.294)       0:00:02.725 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_power_on] ********************************************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.023)       0:00:02.749 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_power_on.yml for instance

TASK [Reset mock to power On] **************************************************
Wednesday 11 March 2026  19:11:06 +0000 (0:00:00.025)       0:00:02.775 *******
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Wednesday 11 March 2026  19:11:07 +0000 (0:00:00.304)       0:00:03.079 *******

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:07 +0000 (0:00:00.031)       0:00:03.110 *******
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Wednesday 11 March 2026  19:11:07 +0000 (0:00:00.302)       0:00:03.413 *******
skipping: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Wednesday 11 March 2026  19:11:07 +0000 (0:00:00.019)       0:00:03.433 *******
ok: [instance]

TASK [Query mock state after power_on (already on)] ****************************
Wednesday 11 March 2026  19:11:07 +0000 (0:00:00.310)       0:00:03.743 *******
ok: [instance]

TASK [Assert host is still On] *************************************************
Wednesday 11 March 2026  19:11:08 +0000 (0:00:00.307)       0:00:04.051 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power Off] *************************************************
Wednesday 11 March 2026  19:11:08 +0000 (0:00:00.024)       0:00:04.075 *******
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Wednesday 11 March 2026  19:11:08 +0000 (0:00:00.297)       0:00:04.373 *******

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:08 +0000 (0:00:00.028)       0:00:04.401 *******
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Wednesday 11 March 2026  19:11:08 +0000 (0:00:00.286)       0:00:04.687 *******
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Wednesday 11 March 2026  19:11:09 +0000 (0:00:00.304)       0:00:04.992 *******
ok: [instance]

TASK [Query mock state after power_on (was off)] *******************************
Wednesday 11 March 2026  19:11:09 +0000 (0:00:00.296)       0:00:05.289 *******
ok: [instance]

TASK [Assert host is now On] ***************************************************
Wednesday 11 March 2026  19:11:09 +0000 (0:00:00.308)       0:00:05.597 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_check_usb_boot] **************************************************
Wednesday 11 March 2026  19:11:09 +0000 (0:00:00.026)       0:00:05.623 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_check_usb_boot.yml for instance

TASK [Reset mock with usb_boot Enabled] ****************************************
Wednesday 11 March 2026  19:11:09 +0000 (0:00:00.028)       0:00:05.651 *******
ok: [instance]

TASK [Include bm_check_usb_boot] ***********************************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.303)       0:00:05.955 *******

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.027)       0:00:05.982 *******
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.286)       0:00:06.269 *******
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.037)       0:00:06.306 *******
skipping: [instance]

TASK [Assert _usb_boot_enabled is true] ****************************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.033)       0:00:06.339 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.035)       0:00:06.374 *******
ok: [instance]

TASK [Include bm_check_usb_boot (expect failure)] ******************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.293)       0:00:06.667 *******

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Wednesday 11 March 2026  19:11:10 +0000 (0:00:00.028)       0:00:06.696 *******
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.319)       0:00:07.016 *******
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.036)       0:00:07.052 *******
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [Assert failure was about GenericUsbBoot] *********************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.034)       0:00:07.087 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_ensure_usb_boot] *************************************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.023)       0:00:07.110 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_ensure_usb_boot.yml for instance

TASK [Reset mock with usb_boot Enabled and host Off] ***************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.031)       0:00:07.141 *******
ok: [instance]

TASK [Include bm_ensure_usb_boot] **********************************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.283)       0:00:07.425 *******

TASK [reproducer : Check current GenericUsbBoot state] *************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.034)       0:00:07.459 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.021)       0:00:07.481 *******
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.288)       0:00:07.770 *******
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Wednesday 11 March 2026  19:11:11 +0000 (0:00:00.035)       0:00:07.805 *******
skipping: [instance]

TASK [Query mock state] ********************************************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.034)       0:00:07.839 *******
ok: [instance]

TASK [Assert host stayed Off (no power cycle needed)] **************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.295)       0:00:08.135 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled and host Off] **************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.026)       0:00:08.161 *******
ok: [instance]

TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.291)       0:00:08.452 *******

TASK [reproducer : Check current GenericUsbBoot state] *************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.033)       0:00:08.486 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Wednesday 11 March 2026  19:11:12 +0000 (0:00:00.027)       0:00:08.513 *******
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.312)       0:00:08.826 *******
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.037)       0:00:08.864 *******
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [reproducer : Fail if auto-enable is off] *********************************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.033)       0:00:08.897 *******
skipping: [instance]

TASK [reproducer : Set GenericUsbBoot BIOS attribute] **************************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.037)       0:00:08.934 *******
ok: [instance]

TASK [reproducer : Create BIOS config job to schedule the change] **************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.296)       0:00:09.231 *******
ok: [instance]

TASK [reproducer : Power off before applying BIOS change] **********************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.294)       0:00:09.525 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_off.yml for instance

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:13 +0000 (0:00:00.027)       0:00:09.552 *******
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.312)       0:00:09.865 *******
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.021)       0:00:09.886 *******
skipping: [instance]

TASK [reproducer : Power on to apply BIOS config job during POST] **************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.019)       0:00:09.906 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_on.yml for instance

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.027)       0:00:09.934 *******
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.292)       0:00:10.226 *******
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Wednesday 11 March 2026  19:11:14 +0000 (0:00:00.312)       0:00:10.538 *******
ok: [instance]

TASK [reproducer : Power off after BIOS change applied] ************************
Wednesday 11 March 2026  19:11:15 +0000 (0:00:00.290)       0:00:10.828 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_off.yml for instance

TASK [reproducer : Query current power state] **********************************
Wednesday 11 March 2026  19:11:15 +0000 (0:00:00.029)       0:00:10.858 *******
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Wednesday 11 March 2026  19:11:15 +0000 (0:00:00.298)       0:00:11.157 *******
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Wednesday 11 March 2026  19:11:15 +0000 (0:00:00.289)       0:00:11.446 *******
ok: [instance]

TASK [Query mock state after auto-enable] **************************************
Wednesday 11 March 2026  19:11:15 +0000 (0:00:00.298)       0:00:11.745 *******
ok: [instance]

TASK [Assert BIOS updated and host left Off] ***********************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.296)       0:00:12.041 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.028)       0:00:12.070 *******
ok: [instance]

TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.297)       0:00:12.367 *******

TASK [reproducer : Check current GenericUsbBoot state] *************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.032)       0:00:12.400 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.024)       0:00:12.424 *******
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.294)       0:00:12.718 *******
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.035)       0:00:12.754 *******
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [reproducer : Fail if auto-enable is off] *********************************
Wednesday 11 March 2026  19:11:16 +0000 (0:00:00.037)       0:00:12.792 *******
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443. Set cifmw_bm_agent_enable_usb_boot: true in vars.yaml to allow this playbook to enable it automatically (requires a reboot cycle)."}

TASK [Assert failure mentions GenericUsbBoot or auto-enable] *******************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.037)       0:00:12.829 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_eject_vmedia] ****************************************************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.026)       0:00:12.855 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_eject_vmedia.yml for instance

TASK [Reset mock with VirtualMedia inserted] ***********************************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.031)       0:00:12.887 *******
ok: [instance]

TASK [Include bm_eject_vmedia] *************************************************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.292)       0:00:13.180 *******

TASK [reproducer : Eject VirtualMedia] *****************************************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.025)       0:00:13.206 *******
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Wednesday 11 March 2026  19:11:17 +0000 (0:00:00.293)       0:00:13.499 *******
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state after eject] ********************************************
Wednesday 11 March 2026  19:11:22 +0000 (0:00:05.033)       0:00:18.532 *******
ok: [instance]

TASK [Assert VirtualMedia is ejected] ******************************************
Wednesday 11 March 2026  19:11:23 +0000 (0:00:00.313)       0:00:18.846 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia not inserted] *******************************
Wednesday 11 March 2026  19:11:23 +0000 (0:00:00.033)       0:00:18.880 *******
ok: [instance]

TASK [Include bm_eject_vmedia (idempotent)] ************************************
Wednesday 11 March 2026  19:11:23 +0000 (0:00:00.310)       0:00:19.190 *******

TASK [reproducer : Eject VirtualMedia] *****************************************
Wednesday 11 March 2026  19:11:23 +0000 (0:00:00.026)       0:00:19.217 *******
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Wednesday 11 March 2026  19:11:23 +0000 (0:00:00.295)       0:00:19.512 *******
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state] ********************************************************
Wednesday 11 March 2026  19:11:28 +0000 (0:00:05.033)       0:00:24.546 *******
ok: [instance]

TASK [Assert VirtualMedia is still not inserted] *******************************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.278)       0:00:24.825 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_discover_vmedia_target] ******************************************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.030)       0:00:24.855 *******
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_discover_vmedia.yml for instance

TASK [Reset mock with VirtualMedia inserted] ***********************************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.036)       0:00:24.892 *******
ok: [instance]

TASK [Include bm_discover_vmedia_target (auto-discover)] ***********************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.284)       0:00:25.176 *******

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.035)       0:00:25.211 *******
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Wednesday 11 March 2026  19:11:29 +0000 (0:00:00.293)       0:00:25.505 *******
ok: [instance] => (item=Boot0001)
ok: [instance] => (item=Boot0003)
ok: [instance] => (item=Boot0004)
ok: [instance] => (item=Boot0005)
ok: [instance] => (item=Boot0006)

TASK [reproducer : Build list of known UEFI device paths] **********************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:01.426)       0:00:26.932 *******
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.044)       0:00:26.976 *******
skipping: [instance]

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.026)       0:00:27.003 *******
skipping: [instance] => (item=PXE Device 1: Embedded NIC 1 Port 1 Partition 1)
skipping: [instance] => (item=Virtual Floppy Drive)
ok: [instance] => (item=Virtual Optical Drive)
skipping: [instance] => (item=Integrated RAID Controller 1: Red Hat Enterprise Linux)
skipping: [instance] => (item=Generic USB Boot)

TASK [reproducer : Fail if no Virtual Optical Drive found] *********************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.068)       0:00:27.072 *******
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.025)       0:00:27.097 *******
ok: [instance] => {
    "msg": "VirtualMedia UEFI path: PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0)"
}

TASK [reproducer : Clear pending iDRAC config jobs that block boot override] ***
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.023)       0:00:27.121 *******
ok: [instance]

TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
Wednesday 11 March 2026  19:11:31 +0000 (0:00:00.290)       0:00:27.411 *******
Pausing for 10 seconds
ok: [instance]

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Wednesday 11 March 2026  19:11:41 +0000 (0:00:10.036)       0:00:37.447 *******
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Wednesday 11 March 2026  19:11:41 +0000 (0:00:00.290)       0:00:37.738 *******
ok: [instance]

TASK [reproducer : Assert boot override is set correctly] **********************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.296)       0:00:38.034 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.030)       0:00:38.065 *******
ok: [instance]

TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.295)       0:00:38.361 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Assert discovered path is Virtual Optical Drive] *************************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.039)       0:00:38.400 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Query mock state after discover] *****************************************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.040)       0:00:38.440 *******
ok: [instance]

TASK [Assert boot override was set] ********************************************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.303)       0:00:38.743 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia inserted] ***********************************
Wednesday 11 March 2026  19:11:42 +0000 (0:00:00.031)       0:00:38.775 *******
ok: [instance]

TASK [Include bm_discover_vmedia_target with valid explicit path] **************
Wednesday 11 March 2026  19:11:43 +0000 (0:00:00.319)       0:00:39.095 *******

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Wednesday 11 March 2026  19:11:43 +0000 (0:00:00.035)       0:00:39.130 *******
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Wednesday 11 March 2026  19:11:43 +0000 (0:00:00.309)       0:00:39.439 *******
ok: [instance] => (item=Boot0001)
ok: [instance] => (item=Boot0003)
ok: [instance] => (item=Boot0004)
ok: [instance] => (item=Boot0005)
ok: [instance] => (item=Boot0006)

TASK [reproducer : Build list of known UEFI device paths] **********************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:01.423)       0:00:40.863 *******
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.041)       0:00:40.905 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.047)       0:00:40.952 *******
skipping: [instance] => (item=PXE Device 1: Embedded NIC 1 Port 1 Partition 1)
skipping: [instance] => (item=Virtual Floppy Drive)
skipping: [instance] => (item=Virtual Optical Drive)
skipping: [instance] => (item=Integrated RAID Controller 1: Red Hat Enterprise Linux)
skipping: [instance] => (item=Generic USB Boot)
skipping: [instance]

TASK [reproducer : Fail if no Virtual Optical Drive found] *********************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.065)       0:00:41.017 *******
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.027)       0:00:41.045 *******
ok: [instance] => {
    "msg": "VirtualMedia UEFI path: PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0)"
}

TASK [reproducer : Clear pending iDRAC config jobs that block boot override] ***
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.024)       0:00:41.069 *******
ok: [instance]

TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
Wednesday 11 March 2026  19:11:45 +0000 (0:00:00.315)       0:00:41.384 *******
Pausing for 10 seconds
ok: [instance]

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Wednesday 11 March 2026  19:11:55 +0000 (0:00:10.034)       0:00:51.419 *******
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Wednesday 11 March 2026  19:11:55 +0000 (0:00:00.305)       0:00:51.724 *******
ok: [instance]

TASK [reproducer : Assert boot override is set correctly] **********************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.299)       0:00:52.024 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.029)       0:00:52.054 *******
ok: [instance]

TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.299)       0:00:52.353 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Query mock state] ********************************************************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.042)       0:00:52.396 *******
ok: [instance]

TASK [Assert boot override set with user-provided path] ************************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.303)       0:00:52.699 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia inserted] ***********************************
Wednesday 11 March 2026  19:11:56 +0000 (0:00:00.027)       0:00:52.726 *******
ok: [instance]

TASK [Include bm_discover_vmedia_target with invalid path (expect failure)] ****
Wednesday 11 March 2026  19:11:57 +0000 (0:00:00.318)       0:00:53.045 *******

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Wednesday 11 March 2026  19:11:57 +0000 (0:00:00.034)       0:00:53.079 *******
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Wednesday 11 March 2026  19:11:57 +0000 (0:00:00.297)       0:00:53.376 *******
ok: [instance] => (item=Boot0001)
ok: [instance] => (item=Boot0003)
ok: [instance] => (item=Boot0004)
ok: [instance] => (item=Boot0005)
ok: [instance] => (item=Boot0006)

TASK [reproducer : Build list of known UEFI device paths] **********************
Wednesday 11 March 2026  19:11:58 +0000 (0:00:01.425)       0:00:54.801 *******
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Wednesday 11 March 2026  19:11:59 +0000 (0:00:00.042)       0:00:54.844 *******
fatal: [instance]: FAILED! => {
    "assertion": "cifmw_bm_agent_vmedia_uefi_path in _known_uefi_paths",
    "changed": false,
    "evaluated_to": false,
    "msg": "cifmw_bm_agent_vmedia_uefi_path 'PciRoot(0x0)/INVALID/PATH' is not listed in UEFI boot options. Available paths: PXE Device 1: Embedded NIC 1 Port 1 Partition 1 -> VenHw(3A191845-5F86-4E78-8FCE-C4CFF59F9DAA), Virtual Floppy Drive -> PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x1), Virtual Optical Drive -> PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0), Integrated RAID Controller 1: Red Hat Enterprise Linux -> HD(2,GPT,FF726BC2-263F-EE4A-BAE7-7CACE574EBD8,0x1000,0x3F800)/\\EFI\\redhat\\shimx64.efi, Generic USB Boot -> VenHw(0C8CB6CC-13AE-45F4-BBCD-6A25E98AC250)"
}

TASK [Assert failure was about UEFI path] **************************************
Wednesday 11 March 2026  19:11:59 +0000 (0:00:00.044)       0:00:54.889 *******
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

PLAY RECAP *********************************************************************
instance                   : ok=110  changed=0    unreachable=0    failed=0    skipped=12   rescued=5    ignored=0

Wednesday 11 March 2026  19:11:59 +0000 (0:00:00.048)       0:00:54.938 *******
===============================================================================
reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.04s
reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.03s
reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.03s
reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.03s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.43s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.43s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.42s
Reset mock to power Off ------------------------------------------------- 0.42s
Query mock state after power_off (already off) -------------------------- 0.33s
Reset mock with VirtualMedia inserted ----------------------------------- 0.32s
reproducer : Read GenericUsbBoot BIOS attribute ------------------------- 0.32s
Reset mock with VirtualMedia inserted ----------------------------------- 0.32s
reproducer : Clear pending iDRAC config jobs that block boot override --- 0.32s
Query mock state after eject -------------------------------------------- 0.31s
reproducer : Query current power state ---------------------------------- 0.31s
reproducer : Read GenericUsbBoot BIOS attribute ------------------------- 0.31s
reproducer : Power on bare metal host ----------------------------------- 0.31s
Reset mock with VirtualMedia not inserted ------------------------------- 0.31s
reproducer : Wait for host POST to complete ----------------------------- 0.31s
reproducer : Fetch UEFI boot option IDs --------------------------------- 0.31s

PLAY [Cleanup mock iDRAC server] ***********************************************

TASK [Stop mock iDRAC server] **************************************************
Wednesday 11 March 2026  19:11:59 +0000 (0:00:00.021)       0:00:00.021 *******
fatal: [instance]: FAILED! => {"changed": false, "cmd": "pkill -f 'mock_idrac.py.*--port 8443' || true", "delta": "0:00:00.014897", "end": "2026-03-11 19:11:59.907799", "msg": "non-zero return code", "rc": -15, "start": "2026-03-11 19:11:59.892902", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

PLAY RECAP *********************************************************************
instance                   : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

Wednesday 11 March 2026  19:11:59 +0000 (0:00:00.310)       0:00:00.332 *******
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.31s

PLAY [Cleanup mock iDRAC server] ***********************************************

TASK [Stop mock iDRAC server] **************************************************
Wednesday 11 March 2026  19:12:00 +0000 (0:00:00.022)       0:00:00.022 *******
fatal: [instance]: FAILED! => {"changed": false, "cmd": "pkill -f 'mock_idrac.py.*--port 8443' || true", "delta": "0:00:00.015574", "end": "2026-03-11 19:12:00.680105", "msg": "non-zero return code", "rc": -15, "start": "2026-03-11 19:12:00.664531", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

PLAY RECAP *********************************************************************
instance                   : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

Wednesday 11 March 2026  19:12:00 +0000 (0:00:00.294)       0:00:00.316 *******
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.29s