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

TASK [Create mock server directory] ********************************************
Thursday 12 March 2026  11:59:20 +0000 (0:00:00.026)       0:00:00.026 ********
changed: [instance]

TASK [Generate self-signed TLS certificate] ************************************
Thursday 12 March 2026  11:59:20 +0000 (0:00:00.342)       0:00:00.368 ********
changed: [instance]

TASK [Copy mock iDRAC server script] *******************************************
Thursday 12 March 2026  11:59:21 +0000 (0:00:00.359)       0:00:00.728 ********
changed: [instance]

TASK [Start mock iDRAC server] *************************************************
Thursday 12 March 2026  11:59:21 +0000 (0:00:00.518)       0:00:01.246 ********
changed: [instance]

TASK [Record mock server PID] **************************************************
Thursday 12 March 2026  11:59:21 +0000 (0:00:00.196)       0:00:01.442 ********
ok: [instance]

TASK [Wait for mock iDRAC to respond] ******************************************
Thursday 12 March 2026  11:59:22 +0000 (0:00:00.214)       0:00:01.657 ********
ok: [instance]

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

Thursday 12 March 2026  11:59:22 +0000 (0:00:00.434)       0:00:02.091 ********
===============================================================================
Copy mock iDRAC server script ------------------------------------------- 0.52s
Wait for mock iDRAC to respond ------------------------------------------ 0.43s
Generate self-signed TLS certificate ------------------------------------ 0.36s
Create mock server directory -------------------------------------------- 0.34s
Record mock server PID -------------------------------------------------- 0.21s
Start mock iDRAC server ------------------------------------------------- 0.20s

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

TASK [Test bm_power_off] *******************************************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.054)       0:00:00.054 ********
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  11:59:23 +0000 (0:00:00.025)       0:00:00.080 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.412)       0:00:00.493 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.028)       0:00:00.521 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.295)       0:00:00.817 ********
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.019)       0:00:00.836 ********
skipping: [instance]

TASK [Query mock state after power_off (already off)] **************************
Thursday 12 March 2026  11:59:23 +0000 (0:00:00.020)       0:00:00.857 ********
ok: [instance]

TASK [Assert host is still Off] ************************************************
Thursday 12 March 2026  11:59:24 +0000 (0:00:00.292)       0:00:01.149 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power On] **************************************************
Thursday 12 March 2026  11:59:24 +0000 (0:00:00.022)       0:00:01.172 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 12 March 2026  11:59:24 +0000 (0:00:00.277)       0:00:01.450 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  11:59:24 +0000 (0:00:00.025)       0:00:01.475 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  11:59:24 +0000 (0:00:00.294)       0:00:01.770 ********
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  11:59:25 +0000 (0:00:00.296)       0:00:02.066 ********
ok: [instance]

TASK [Query mock state after power_off (was on)] *******************************
Thursday 12 March 2026  11:59:25 +0000 (0:00:00.300)       0:00:02.367 ********
ok: [instance]

TASK [Assert host is now Off] **************************************************
Thursday 12 March 2026  11:59:25 +0000 (0:00:00.292)       0:00:02.659 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_power_on] ********************************************************
Thursday 12 March 2026  11:59:25 +0000 (0:00:00.021)       0:00:02.681 ********
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  11:59:25 +0000 (0:00:00.024)       0:00:02.706 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 12 March 2026  11:59:26 +0000 (0:00:00.295)       0:00:03.001 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  11:59:26 +0000 (0:00:00.027)       0:00:03.029 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  11:59:26 +0000 (0:00:00.298)       0:00:03.328 ********
skipping: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  11:59:26 +0000 (0:00:00.018)       0:00:03.347 ********
ok: [instance]

TASK [Query mock state after power_on (already on)] ****************************
Thursday 12 March 2026  11:59:26 +0000 (0:00:00.317)       0:00:03.664 ********
ok: [instance]

TASK [Assert host is still On] *************************************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.309)       0:00:03.973 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power Off] *************************************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.021)       0:00:03.995 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.280)       0:00:04.276 ********

TASK [reproducer : Query current power state] **********************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.026)       0:00:04.303 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.289)       0:00:04.593 ********
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  11:59:27 +0000 (0:00:00.295)       0:00:04.889 ********
ok: [instance]

TASK [Query mock state after power_on (was off)] *******************************
Thursday 12 March 2026  11:59:28 +0000 (0:00:00.292)       0:00:05.181 ********
ok: [instance]

TASK [Assert host is now On] ***************************************************
Thursday 12 March 2026  11:59:28 +0000 (0:00:00.282)       0:00:05.463 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_check_usb_boot] **************************************************
Thursday 12 March 2026  11:59:28 +0000 (0:00:00.021)       0:00:05.485 ********
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  11:59:28 +0000 (0:00:00.024)       0:00:05.510 ********
ok: [instance]

TASK [Include bm_check_usb_boot] ***********************************************
Thursday 12 March 2026  11:59:28 +0000 (0:00:00.284)       0:00:05.794 ********

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Thursday 12 March 2026  11:59:28 +0000 (0:00:00.025)       0:00:05.820 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.292)       0:00:06.112 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.032)       0:00:06.144 ********
skipping: [instance]

TASK [Assert _usb_boot_enabled is true] ****************************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.030)       0:00:06.175 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.029)       0:00:06.205 ********
ok: [instance]

TASK [Include bm_check_usb_boot (expect failure)] ******************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.283)       0:00:06.489 ********

TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.025)       0:00:06.514 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.281)       0:00:06.796 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.033)       0:00:06.829 ********
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  11:59:29 +0000 (0:00:00.032)       0:00:06.862 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_ensure_usb_boot] *************************************************
Thursday 12 March 2026  11:59:29 +0000 (0:00:00.020)       0:00:06.883 ********
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  11:59:29 +0000 (0:00:00.030)       0:00:06.913 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot] **********************************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.292)       0:00:07.206 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.032)       0:00:07.239 ********
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  11:59:30 +0000 (0:00:00.021)       0:00:07.260 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.289)       0:00:07.549 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.035)       0:00:07.584 ********
skipping: [instance]

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.031)       0:00:07.616 ********
ok: [instance]

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

TASK [Reset mock with usb_boot Disabled and host Off] **************************
Thursday 12 March 2026  11:59:30 +0000 (0:00:00.025)       0:00:07.924 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.277)       0:00:08.202 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.029)       0:00:08.232 ********
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  11:59:31 +0000 (0:00:00.020)       0:00:08.253 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.281)       0:00:08.535 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.032)       0:00:08.567 ********
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  11:59:31 +0000 (0:00:00.030)       0:00:08.597 ********
skipping: [instance]

TASK [reproducer : Set GenericUsbBoot BIOS attribute] **************************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.029)       0:00:08.627 ********
ok: [instance]

TASK [reproducer : Create BIOS config job to schedule the change] **************
Thursday 12 March 2026  11:59:31 +0000 (0:00:00.297)       0:00:08.924 ********
ok: [instance]

TASK [reproducer : Power off before applying BIOS change] **********************
Thursday 12 March 2026  11:59:32 +0000 (0:00:00.281)       0:00:09.206 ********
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  11:59:32 +0000 (0:00:00.024)       0:00:09.231 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  11:59:32 +0000 (0:00:00.282)       0:00:09.513 ********
skipping: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  11:59:32 +0000 (0:00:00.017)       0:00:09.530 ********
skipping: [instance]

TASK [reproducer : Power on to apply BIOS config job during POST] **************
Thursday 12 March 2026  11:59:32 +0000 (0:00:00.017)       0:00:09.548 ********
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  11:59:32 +0000 (0:00:00.024)       0:00:09.572 ********
ok: [instance]

TASK [reproducer : Power on bare metal host] ***********************************
Thursday 12 March 2026  11:59:32 +0000 (0:00:00.288)       0:00:09.860 ********
ok: [instance]

TASK [reproducer : Wait for host POST to complete] *****************************
Thursday 12 March 2026  11:59:33 +0000 (0:00:00.284)       0:00:10.144 ********
ok: [instance]

TASK [reproducer : Power off after BIOS change applied] ************************
Thursday 12 March 2026  11:59:33 +0000 (0:00:00.282)       0:00:10.427 ********
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  11:59:33 +0000 (0:00:00.027)       0:00:10.455 ********
ok: [instance]

TASK [reproducer : Force power off via Redfish] ********************************
Thursday 12 March 2026  11:59:33 +0000 (0:00:00.289)       0:00:10.744 ********
ok: [instance]

TASK [reproducer : Wait for host to power off] *********************************
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.293)       0:00:11.038 ********
ok: [instance]

TASK [Query mock state after auto-enable] **************************************
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.295)       0:00:11.333 ********
ok: [instance]

TASK [Assert BIOS updated and host left Off] ***********************************
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.284)       0:00:11.618 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.022)       0:00:11.640 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.282)       0:00:11.923 ********

TASK [reproducer : Check current GenericUsbBoot state] *************************
Thursday 12 March 2026  11:59:34 +0000 (0:00:00.028)       0:00:11.952 ********
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  11:59:35 +0000 (0:00:00.020)       0:00:11.972 ********
ok: [instance]

TASK [reproducer : Set GenericUsbBoot status fact] *****************************
Thursday 12 March 2026  11:59:35 +0000 (0:00:00.281)       0:00:12.254 ********
ok: [instance]

TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
Thursday 12 March 2026  11:59:35 +0000 (0:00:00.031)       0:00:12.285 ********
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  11:59:35 +0000 (0:00:00.031)       0:00:12.317 ********
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  11:59:35 +0000 (0:00:00.032)       0:00:12.349 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_eject_vmedia] ****************************************************
Thursday 12 March 2026  11:59:35 +0000 (0:00:00.021)       0:00:12.371 ********
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  11:59:35 +0000 (0:00:00.030)       0:00:12.401 ********
ok: [instance]

TASK [Include bm_eject_vmedia] *************************************************
Thursday 12 March 2026  11:59:35 +0000 (0:00:00.294)       0:00:12.696 ********

TASK [reproducer : Eject VirtualMedia] *****************************************
Thursday 12 March 2026  11:59:35 +0000 (0:00:00.025)       0:00:12.722 ********
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Thursday 12 March 2026  11:59:36 +0000 (0:00:00.295)       0:00:13.017 ********
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state after eject] ********************************************
Thursday 12 March 2026  11:59:41 +0000 (0:00:05.028)       0:00:18.046 ********
ok: [instance]

TASK [Assert VirtualMedia is ejected] ******************************************
Thursday 12 March 2026  11:59:41 +0000 (0:00:00.293)       0:00:18.339 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia not inserted] *******************************
Thursday 12 March 2026  11:59:41 +0000 (0:00:00.029)       0:00:18.369 ********
ok: [instance]

TASK [Include bm_eject_vmedia (idempotent)] ************************************
Thursday 12 March 2026  11:59:41 +0000 (0:00:00.285)       0:00:18.654 ********

TASK [reproducer : Eject VirtualMedia] *****************************************
Thursday 12 March 2026  11:59:41 +0000 (0:00:00.024)       0:00:18.679 ********
ok: [instance]

TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
Thursday 12 March 2026  11:59:42 +0000 (0:00:00.290)       0:00:18.970 ********
Pausing for 5 seconds
ok: [instance]

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  11:59:47 +0000 (0:00:05.028)       0:00:23.999 ********
ok: [instance]

TASK [Assert VirtualMedia is still not inserted] *******************************
Thursday 12 March 2026  11:59:47 +0000 (0:00:00.289)       0:00:24.288 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_discover_vmedia_target] ******************************************
Thursday 12 March 2026  11:59:47 +0000 (0:00:00.030)       0:00:24.318 ********
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  11:59:47 +0000 (0:00:00.034)       0:00:24.353 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target (auto-discover)] ***********************
Thursday 12 March 2026  11:59:47 +0000 (0:00:00.290)       0:00:24.643 ********

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Thursday 12 March 2026  11:59:47 +0000 (0:00:00.034)       0:00:24.678 ********
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  11:59:48 +0000 (0:00:00.293)       0:00:24.971 ********
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  11:59:49 +0000 (0:00:01.445)       0:00:26.417 ********
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Thursday 12 March 2026  11:59:49 +0000 (0:00:00.039)       0:00:26.456 ********
skipping: [instance]

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Thursday 12 March 2026  11:59:49 +0000 (0:00:00.023)       0:00:26.479 ********
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  11:59:49 +0000 (0:00:00.066)       0:00:26.546 ********
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Thursday 12 March 2026  11:59:49 +0000 (0:00:00.022)       0:00:26.568 ********
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  11:59:49 +0000 (0:00:00.020)       0:00:26.588 ********
ok: [instance]

TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
Thursday 12 March 2026  11:59:49 +0000 (0:00:00.297)       0:00:26.886 ********
Pausing for 10 seconds
ok: [instance]

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Thursday 12 March 2026  11:59:59 +0000 (0:00:10.030)       0:00:36.916 ********
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Thursday 12 March 2026  12:00:00 +0000 (0:00:00.295)       0:00:37.211 ********
ok: [instance]

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

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Thursday 12 March 2026  12:00:00 +0000 (0:00:00.025)       0:00:37.554 ********
ok: [instance]

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

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

TASK [Query mock state after discover] *****************************************
Thursday 12 March 2026  12:00:00 +0000 (0:00:00.037)       0:00:37.939 ********
ok: [instance]

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

TASK [Reset mock with VirtualMedia inserted] ***********************************
Thursday 12 March 2026  12:00:01 +0000 (0:00:00.031)       0:00:38.277 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target with valid explicit path] **************
Thursday 12 March 2026  12:00:01 +0000 (0:00:00.314)       0:00:38.591 ********

TASK [reproducer : Fetch UEFI boot option IDs] *********************************
Thursday 12 March 2026  12:00:01 +0000 (0:00:00.035)       0:00:38.627 ********
ok: [instance]

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  12:00:01 +0000 (0:00:00.323)       0:00:38.950 ********
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  12:00:03 +0000 (0:00:01.422)       0:00:40.372 ********
ok: [instance]

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

TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
Thursday 12 March 2026  12:00:03 +0000 (0:00:00.040)       0:00:40.455 ********
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  12:00:03 +0000 (0:00:00.058)       0:00:40.513 ********
skipping: [instance]

TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
Thursday 12 March 2026  12:00:03 +0000 (0:00:00.023)       0:00:40.536 ********
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  12:00:03 +0000 (0:00:00.020)       0:00:40.557 ********
ok: [instance]

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

TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
Thursday 12 March 2026  12:00:13 +0000 (0:00:10.032)       0:00:50.889 ********
ok: [instance]

TASK [reproducer : Verify boot override was applied] ***************************
Thursday 12 March 2026  12:00:14 +0000 (0:00:00.287)       0:00:51.176 ********
ok: [instance]

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

TASK [reproducer : Verify VirtualMedia is still inserted] **********************
Thursday 12 March 2026  12:00:14 +0000 (0:00:00.026)       0:00:51.492 ********
ok: [instance]

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

TASK [Query mock state] ********************************************************
Thursday 12 March 2026  12:00:14 +0000 (0:00:00.036)       0:00:51.812 ********
ok: [instance]

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

TASK [Reset mock with VirtualMedia inserted] ***********************************
Thursday 12 March 2026  12:00:15 +0000 (0:00:00.020)       0:00:52.112 ********
ok: [instance]

TASK [Include bm_discover_vmedia_target with invalid path (expect failure)] ****
Thursday 12 March 2026  12:00:15 +0000 (0:00:00.279)       0:00:52.391 ********

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

TASK [reproducer : Fetch each UEFI boot option detail] *************************
Thursday 12 March 2026  12:00:15 +0000 (0:00:00.278)       0:00:52.701 ********
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  12:00:17 +0000 (0:00:01.359)       0:00:54.060 ********
ok: [instance]

TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
Thursday 12 March 2026  12:00:17 +0000 (0:00:00.038)       0:00:54.099 ********
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  12:00:17 +0000 (0:00:00.041)       0:00:54.141 ********
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  12:00:17 +0000 (0:00:00.041)       0:00:54.182 ********
===============================================================================
reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.03s
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.45s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.42s
reproducer : Fetch each UEFI boot option detail ------------------------- 1.36s
Reset mock to power Off ------------------------------------------------- 0.41s
reproducer : Fetch UEFI boot option IDs --------------------------------- 0.32s
reproducer : Verify boot override was applied --------------------------- 0.32s
reproducer : Wait for host POST to complete ----------------------------- 0.32s
Reset mock with VirtualMedia inserted ----------------------------------- 0.31s
Query mock state after power_on (already on) ---------------------------- 0.31s
reproducer : Verify VirtualMedia is still inserted ---------------------- 0.31s
Query mock state after discover ----------------------------------------- 0.31s
reproducer : Wait for host to power off --------------------------------- 0.30s
reproducer : Clear pending iDRAC config jobs that block boot override --- 0.30s
reproducer : Query current power state ---------------------------------- 0.30s
reproducer : Set GenericUsbBoot BIOS attribute -------------------------- 0.30s
reproducer : Clear pending iDRAC config jobs that block boot override --- 0.30s

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

TASK [Stop mock iDRAC server] **************************************************
Thursday 12 March 2026  12:00:17 +0000 (0:00:00.026)       0:00:00.026 ********
fatal: [instance]: FAILED! => {"changed": false, "cmd": "pkill -f 'mock_idrac.py.*--port 8443' || true", "delta": "0:00:00.014953", "end": "2026-03-12 12:00:17.972421", "msg": "non-zero return code", "rc": -15, "start": "2026-03-12 12:00:17.957468", "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  12:00:17 +0000 (0:00:00.302)       0:00:00.329 ********
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.30s

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

TASK [Stop mock iDRAC server] **************************************************
Thursday 12 March 2026  12:00:18 +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.013866", "end": "2026-03-12 12:00:18.755310", "msg": "non-zero return code", "rc": -15, "start": "2026-03-12 12:00:18.741444", "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  12:00:18 +0000 (0:00:00.293)       0:00:00.316 ********
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.29s