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

TASK [Create mock server directory] ********************************************
Thursday 12 March 2026  10:40:16 +0000 (0:00:00.024)       0:00:00.024 ********
changed: [instance]

TASK [Generate self-signed TLS certificate] ************************************
Thursday 12 March 2026  10:40:16 +0000 (0:00:00.313)       0:00:00.338 ********
changed: [instance]

TASK [Copy mock iDRAC server script] *******************************************
Thursday 12 March 2026  10:40:17 +0000 (0:00:00.354)       0:00:00.692 ********
changed: [instance]

TASK [Start mock iDRAC server] *************************************************
Thursday 12 March 2026  10:40:17 +0000 (0:00:00.469)       0:00:01.161 ********
changed: [instance]

TASK [Record mock server PID] **************************************************
Thursday 12 March 2026  10:40:17 +0000 (0:00:00.174)       0:00:01.336 ********
ok: [instance]

TASK [Wait for mock iDRAC to respond] ******************************************
Thursday 12 March 2026  10:40:17 +0000 (0:00:00.185)       0:00:01.522 ********
ok: [instance]

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

Thursday 12 March 2026  10:40:18 +0000 (0:00:00.385)       0:00:01.908 ********
===============================================================================
Copy mock iDRAC server script ------------------------------------------- 0.47s
Wait for mock iDRAC to respond ------------------------------------------ 0.39s
Generate self-signed TLS certificate ------------------------------------ 0.35s
Create mock server directory -------------------------------------------- 0.31s
Record mock server PID -------------------------------------------------- 0.19s
Start mock iDRAC server ------------------------------------------------- 0.17s

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

TASK [Test bm_power_off] *******************************************************
Thursday 12 March 2026  10:40:18 +0000 (0:00:00.043)       0:00:00.043 ********
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] *************************************************
Thursday 12 March 2026  10:40:18 +0000 (0:00:00.020)       0:00:00.064 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.378)       0:00:00.442 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.026)       0:00:00.469 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.269)       0:00:00.739 ********
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.015)       0:00:00.754 ********
skipping: [instance]

TASK [Query mock state after power_off (already off)] **************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.018)       0:00:00.772 ********
ok: [instance]

TASK [Assert host is still Off] ************************************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.267)       0:00:01.040 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power On] **************************************************
Thursday 12 March 2026  10:40:19 +0000 (0:00:00.018)       0:00:01.059 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 12 March 2026  10:40:20 +0000 (0:00:00.263)       0:00:01.322 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  10:40:20 +0000 (0:00:00.023)       0:00:01.345 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  10:40:20 +0000 (0:00:00.267)       0:00:01.613 ********
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  10:40:20 +0000 (0:00:00.265)       0:00:01.879 ********
ok: [instance]

TASK [Query mock state after power_off (was on)] *******************************
Thursday 12 March 2026  10:40:20 +0000 (0:00:00.279)       0:00:02.159 ********
ok: [instance]

TASK [Assert host is now Off] **************************************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.262)       0:00:02.421 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_power_on] ********************************************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.019)       0:00:02.441 ********
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] **************************************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.022)       0:00:02.463 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.272)       0:00:02.735 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.024)       0:00:02.760 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.279)       0:00:03.039 ********
skipping: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  10:40:21 +0000 (0:00:00.015)       0:00:03.054 ********
ok: [instance]

TASK [Query mock state after power_on (already on)] ****************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.276)       0:00:03.331 ********
ok: [instance]

TASK [Assert host is still On] *************************************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.272)       0:00:03.604 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power Off] *************************************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.019)       0:00:03.624 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.265)       0:00:03.889 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.023)       0:00:03.913 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  10:40:22 +0000 (0:00:00.269)       0:00:04.182 ********
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  10:40:23 +0000 (0:00:00.283)       0:00:04.465 ********
ok: [instance]

TASK [Query mock state after power_on (was off)] *******************************
Thursday 12 March 2026  10:40:23 +0000 (0:00:00.270)       0:00:04.736 ********
ok: [instance]

TASK [Assert host is now On] ***************************************************
Thursday 12 March 2026  10:40:23 +0000 (0:00:00.267)       0:00:05.003 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_check_usb_boot] **************************************************
Thursday 12 March 2026  10:40:23 +0000 (0:00:00.018)       0:00:05.022 ********
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] ****************************************
Thursday 12 March 2026  10:40:23 +0000 (0:00:00.022)       0:00:05.044 ********
ok: [instance]

TASK [Include bm_check_usb_boot] ***********************************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.267)       0:00:05.312 ********

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.023)       0:00:05.335 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.271)       0:00:05.607 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.029)       0:00:05.636 ********
skipping: [instance]

TASK [Assert _usb_boot_enabled is true] ****************************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.027)       0:00:05.664 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.027)       0:00:05.691 ********
ok: [instance]

TASK [Include bm_check_usb_boot (expect failure)] ******************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.267)       0:00:05.959 ********

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.024)       0:00:05.983 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  10:40:24 +0000 (0:00:00.276)       0:00:06.259 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.029)       0:00:06.289 ********
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [Assert failure was about GenericUsbBoot] *********************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.029)       0:00:06.319 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_ensure_usb_boot] *************************************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.019)       0:00:06.338 ********
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] ***************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.028)       0:00:06.367 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot] **********************************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.267)       0:00:06.635 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.029)       0:00:06.665 ********
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] *************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.020)       0:00:06.685 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.267)       0:00:06.952 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.030)       0:00:06.983 ********
skipping: [instance]

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.028)       0:00:07.011 ********
ok: [instance]

TASK [Assert host stayed Off (no power cycle needed)] **************************
Thursday 12 March 2026  10:40:25 +0000 (0:00:00.267)       0:00:07.278 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled and host Off] **************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.018)       0:00:07.297 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.272)       0:00:07.570 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.028)       0:00:07.598 ********
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] *************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.020)       0:00:07.619 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.275)       0:00:07.894 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.029)       0:00:07.924 ********
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] *********************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.030)       0:00:07.955 ********
skipping: [instance]

TASK [reproducer : Set GenericUsbBoot BIOS attribute] **************************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.028)       0:00:07.983 ********
ok: [instance]

TASK [reproducer : Create BIOS config job to schedule the change] **************
Thursday 12 March 2026  10:40:26 +0000 (0:00:00.269)       0:00:08.253 ********
ok: [instance]

TASK [reproducer : Power off before applying BIOS change] **********************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.271)       0:00:08.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] **********************************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.021)       0:00:08.546 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.276)       0:00:08.823 ********
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.016)       0:00:08.839 ********
skipping: [instance]

TASK [reproducer : Power on to apply BIOS config job during POST] **************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.018)       0:00:08.857 ********
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] **********************************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.023)       0:00:08.881 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  10:40:27 +0000 (0:00:00.271)       0:00:09.152 ********
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  10:40:28 +0000 (0:00:00.280)       0:00:09.433 ********
ok: [instance]

TASK [reproducer : Power off after BIOS change applied] ************************
Thursday 12 March 2026  10:40:28 +0000 (0:00:00.278)       0:00:09.711 ********
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] **********************************
Thursday 12 March 2026  10:40:28 +0000 (0:00:00.026)       0:00:09.738 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  10:40:28 +0000 (0:00:00.278)       0:00:10.016 ********
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.269)       0:00:10.286 ********
ok: [instance]

TASK [Query mock state after auto-enable] **************************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.283)       0:00:10.569 ********
ok: [instance]

TASK [Assert BIOS updated and host left Off] ***********************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.265)       0:00:10.835 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.020)       0:00:10.855 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.272)       0:00:11.128 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.028)       0:00:11.156 ********
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] *************************
Thursday 12 March 2026  10:40:29 +0000 (0:00:00.020)       0:00:11.176 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.269)       0:00:11.445 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.029)       0:00:11.475 ********
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] *********************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.028)       0:00:11.504 ********
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] *******************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.029)       0:00:11.533 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_eject_vmedia] ****************************************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.020)       0:00:11.553 ********
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] ***********************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.028)       0:00:11.582 ********
ok: [instance]

TASK [Include bm_eject_vmedia] *************************************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.266)       0:00:11.848 ********

TASK [reproducer : Eject VirtualMedia] *****************************************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.024)       0:00:11.872 ********
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Thursday 12 March 2026  10:40:30 +0000 (0:00:00.267)       0:00:12.140 ********
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state after eject] ********************************************
Thursday 12 March 2026  10:40:35 +0000 (0:00:05.024)       0:00:17.164 ********
ok: [instance]

TASK [Assert VirtualMedia is ejected] ******************************************
Thursday 12 March 2026  10:40:36 +0000 (0:00:00.274)       0:00:17.439 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia not inserted] *******************************
Thursday 12 March 2026  10:40:36 +0000 (0:00:00.027)       0:00:17.466 ********
ok: [instance]

TASK [Include bm_eject_vmedia (idempotent)] ************************************
Thursday 12 March 2026  10:40:36 +0000 (0:00:00.267)       0:00:17.734 ********

TASK [reproducer : Eject VirtualMedia] *****************************************
Thursday 12 March 2026  10:40:36 +0000 (0:00:00.023)       0:00:17.758 ********
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Thursday 12 March 2026  10:40:36 +0000 (0:00:00.272)       0:00:18.030 ********
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  10:40:41 +0000 (0:00:05.020)       0:00:23.051 ********
ok: [instance]

TASK [Assert VirtualMedia is still not inserted] *******************************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.272)       0:00:23.324 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_discover_vmedia_target] ******************************************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.027)       0:00:23.351 ********
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] ***********************************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.045)       0:00:23.396 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target (auto-discover)] ***********************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.277)       0:00:23.673 ********

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.033)       0:00:23.707 ********
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  10:40:42 +0000 (0:00:00.277)       0:00:23.985 ********
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] **********************
Thursday 12 March 2026  10:40:44 +0000 (0:00:01.300)       0:00:25.285 ********
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.036)       0:00:25.322 ********
skipping: [instance]

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.019)       0:00:25.342 ********
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] *********************
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.061)       0:00:25.403 ********
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.019)       0:00:25.423 ********
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] ***
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.020)       0:00:25.443 ********
ok: [instance]

TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
Thursday 12 March 2026  10:40:44 +0000 (0:00:00.268)       0:00:25.711 ********
Pausing for 10 seconds
ok: [instance]

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Thursday 12 March 2026  10:40:54 +0000 (0:00:10.029)       0:00:35.741 ********
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Thursday 12 March 2026  10:40:54 +0000 (0:00:00.286)       0:00:36.027 ********
ok: [instance]

TASK [reproducer : Assert boot override is set correctly] **********************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.281)       0:00:36.309 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.023)       0:00:36.332 ********
ok: [instance]

TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.273)       0:00:36.605 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Assert discovered path is Virtual Optical Drive] *************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.034)       0:00:36.640 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Query mock state after discover] *****************************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.034)       0:00:36.674 ********
ok: [instance]

TASK [Assert boot override was set] ********************************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.262)       0:00:36.936 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia inserted] ***********************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.023)       0:00:36.960 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target with valid explicit path] **************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.270)       0:00:37.231 ********

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Thursday 12 March 2026  10:40:55 +0000 (0:00:00.029)       0:00:37.261 ********
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  10:40:56 +0000 (0:00:00.260)       0:00:37.522 ********
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] **********************
Thursday 12 March 2026  10:40:57 +0000 (0:00:01.302)       0:00:38.824 ********
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.035)       0:00:38.860 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.038)       0:00:38.898 ********
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] *********************
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.054)       0:00:38.953 ********
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.019)       0:00:38.972 ********
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] ***
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.018)       0:00:38.991 ********
ok: [instance]

TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
Thursday 12 March 2026  10:40:57 +0000 (0:00:00.269)       0:00:39.261 ********
Pausing for 10 seconds
ok: [instance]

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Thursday 12 March 2026  10:41:08 +0000 (0:00:10.024)       0:00:49.285 ********
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Thursday 12 March 2026  10:41:08 +0000 (0:00:00.283)       0:00:49.569 ********
ok: [instance]

TASK [reproducer : Assert boot override is set correctly] **********************
Thursday 12 March 2026  10:41:08 +0000 (0:00:00.273)       0:00:49.843 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Thursday 12 March 2026  10:41:08 +0000 (0:00:00.022)       0:00:49.865 ********
ok: [instance]

TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
Thursday 12 March 2026  10:41:08 +0000 (0:00:00.269)       0:00:50.135 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  10:41:08 +0000 (0:00:00.033)       0:00:50.168 ********
ok: [instance]

TASK [Assert boot override set with user-provided path] ************************
Thursday 12 March 2026  10:41:09 +0000 (0:00:00.264)       0:00:50.433 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia inserted] ***********************************
Thursday 12 March 2026  10:41:09 +0000 (0:00:00.020)       0:00:50.453 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target with invalid path (expect failure)] ****
Thursday 12 March 2026  10:41:09 +0000 (0:00:00.270)       0:00:50.724 ********

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Thursday 12 March 2026  10:41:09 +0000 (0:00:00.030)       0:00:50.754 ********
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  10:41:09 +0000 (0:00:00.270)       0:00:51.025 ********
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] **********************
Thursday 12 March 2026  10:41:11 +0000 (0:00:01.282)       0:00:52.307 ********
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Thursday 12 March 2026  10:41:11 +0000 (0:00:00.036)       0:00:52.343 ********
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] **************************************
Thursday 12 March 2026  10:41:11 +0000 (0:00:00.038)       0:00:52.382 ********
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

Thursday 12 March 2026  10:41:11 +0000 (0:00:00.037)       0:00:52.419 ********
===============================================================================
reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.03s
reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.02s
reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.02s
reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.02s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.30s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.30s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.28s
Reset mock to power Off ------------------------------------------------- 0.38s
reproducer : Set one-time boot from Virtual Optical Drive --------------- 0.29s
reproducer : Set one-time boot from Virtual Optical Drive --------------- 0.28s
reproducer : Wait for host to power off --------------------------------- 0.28s
reproducer : Power on bare metal host ----------------------------------- 0.28s
reproducer : Verify boot override was applied --------------------------- 0.28s
reproducer : Power on bare metal host ----------------------------------- 0.28s
reproducer : Wait for host to power off --------------------------------- 0.28s
reproducer : Query current power state ---------------------------------- 0.28s
reproducer : Wait for host POST to complete ----------------------------- 0.28s
reproducer : Query current power state ---------------------------------- 0.28s
reproducer : Fetch UEFI boot option IDs --------------------------------- 0.28s
Reset mock with VirtualMedia inserted ----------------------------------- 0.28s

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

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

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

Thursday 12 March 2026  10:41:11 +0000 (0:00:00.279)       0:00:00.302 ********
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.28s

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

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

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

Thursday 12 March 2026  10:41:12 +0000 (0:00:00.282)       0:00:00.305 ********
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.28s