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

TASK [Create mock server directory] ********************************************
Thursday 19 March 2026  10:38:27 +0000 (0:00:00.023)       0:00:00.023 ********
changed: [instance]

TASK [Generate self-signed TLS certificate] ************************************
Thursday 19 March 2026  10:38:27 +0000 (0:00:00.336)       0:00:00.359 ********
changed: [instance]

TASK [Copy mock iDRAC server script] *******************************************
Thursday 19 March 2026  10:38:27 +0000 (0:00:00.343)       0:00:00.702 ********
changed: [instance]

TASK [Start mock iDRAC server] *************************************************
Thursday 19 March 2026  10:38:28 +0000 (0:00:00.466)       0:00:01.169 ********
changed: [instance]

TASK [Record mock server PID] **************************************************
Thursday 19 March 2026  10:38:28 +0000 (0:00:00.180)       0:00:01.349 ********
ok: [instance]

TASK [Wait for mock iDRAC to respond] ******************************************
Thursday 19 March 2026  10:38:28 +0000 (0:00:00.190)       0:00:01.540 ********
ok: [instance]

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

Thursday 19 March 2026  10:38:29 +0000 (0:00:00.393)       0:00:01.933 ********
===============================================================================
Copy mock iDRAC server script ------------------------------------------- 0.47s
Wait for mock iDRAC to respond ------------------------------------------ 0.39s
Generate self-signed TLS certificate ------------------------------------ 0.34s
Create mock server directory -------------------------------------------- 0.34s
Record mock server PID -------------------------------------------------- 0.19s
Start mock iDRAC server ------------------------------------------------- 0.18s

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

TASK [Test bm_power_off] *******************************************************
Thursday 19 March 2026  10:38:29 +0000 (0:00:00.043)       0:00:00.043 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_power_off.yml for instance

TASK [Reset mock to power Off] *************************************************
Thursday 19 March 2026  10:38:29 +0000 (0:00:00.020)       0:00:00.063 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.388)       0:00:00.451 ********

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.022)       0:00:00.474 ********
ok: [instance]

TASK [bm_sno : Force power off via Redfish] ************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.259)       0:00:00.733 ********
skipping: [instance]

TASK [bm_sno : Wait for host to power off] *************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.013)       0:00:00.747 ********
skipping: [instance]

TASK [Query mock state after power_off (already off)] **************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.016)       0:00:00.763 ********
ok: [instance]

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

TASK [Reset mock to power On] **************************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.016)       0:00:01.043 ********
ok: [instance]

TASK [Include bm_power_off] ****************************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.265)       0:00:01.309 ********

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:30 +0000 (0:00:00.020)       0:00:01.329 ********
ok: [instance]

TASK [bm_sno : Force power off via Redfish] ************************************
Thursday 19 March 2026  10:38:31 +0000 (0:00:00.267)       0:00:01.597 ********
ok: [instance]

TASK [bm_sno : Wait for host to power off] *************************************
Thursday 19 March 2026  10:38:31 +0000 (0:00:00.269)       0:00:01.866 ********
ok: [instance]

TASK [Query mock state after power_off (was on)] *******************************
Thursday 19 March 2026  10:38:31 +0000 (0:00:00.277)       0:00:02.144 ********
ok: [instance]

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

TASK [Test bm_power_on] ********************************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.017)       0:00:02.424 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_power_on.yml for instance

TASK [Reset mock to power On] **************************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.022)       0:00:02.446 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.255)       0:00:02.702 ********

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.020)       0:00:02.723 ********
ok: [instance]

TASK [bm_sno : Power on bare metal host] ***************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.262)       0:00:02.985 ********
skipping: [instance]

TASK [bm_sno : Wait for host POST to complete] *********************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.015)       0:00:03.000 ********
ok: [instance]

TASK [bm_sno : Show POST state] ************************************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.279)       0:00:03.280 ********
ok: [instance] => {
    "msg": "POST state: FinishedPost"
}

TASK [Query mock state after power_on (already on)] ****************************
Thursday 19 March 2026  10:38:32 +0000 (0:00:00.029)       0:00:03.310 ********
ok: [instance]

TASK [Assert host is still On with POST complete] ******************************
Thursday 19 March 2026  10:38:33 +0000 (0:00:00.266)       0:00:03.577 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power Off] *************************************************
Thursday 19 March 2026  10:38:33 +0000 (0:00:00.018)       0:00:03.595 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 19 March 2026  10:38:33 +0000 (0:00:00.265)       0:00:03.860 ********

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:33 +0000 (0:00:00.021)       0:00:03.882 ********
ok: [instance]

TASK [bm_sno : Power on bare metal host] ***************************************
Thursday 19 March 2026  10:38:33 +0000 (0:00:00.272)       0:00:04.154 ********
ok: [instance]

TASK [bm_sno : Wait for host POST to complete] *********************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.268)       0:00:04.423 ********
ok: [instance]

TASK [bm_sno : Show POST state] ************************************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.280)       0:00:04.703 ********
ok: [instance] => {
    "msg": "POST state: FinishedPost"
}

TASK [Query mock state after power_on (was off)] *******************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.030)       0:00:04.733 ********
ok: [instance]

TASK [Assert host is now On with POST complete] ********************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.264)       0:00:04.997 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock to power Off without PostState support] ***********************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.018)       0:00:05.016 ********
ok: [instance]

TASK [Include bm_power_on] *****************************************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.271)       0:00:05.288 ********

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:34 +0000 (0:00:00.022)       0:00:05.311 ********
ok: [instance]

TASK [bm_sno : Power on bare metal host] ***************************************
Thursday 19 March 2026  10:38:35 +0000 (0:00:00.273)       0:00:05.584 ********
ok: [instance]

TASK [bm_sno : Wait for host POST to complete] *********************************
Thursday 19 March 2026  10:38:35 +0000 (0:00:00.277)       0:00:05.862 ********
ok: [instance]

TASK [bm_sno : Show POST state] ************************************************
Thursday 19 March 2026  10:38:35 +0000 (0:00:00.292)       0:00:06.154 ********
ok: [instance] => {
    "msg": "POST state: not supported by firmware, used PowerState=On"
}

TASK [Query mock state after power_on (no PostState)] **************************
Thursday 19 March 2026  10:38:35 +0000 (0:00:00.032)       0:00:06.187 ********
ok: [instance]

TASK [Assert host is On (PostState stays null)] ********************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.288)       0:00:06.475 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_check_usb_boot] **************************************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.020)       0:00:06.496 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_check_usb_boot.yml for instance

TASK [Reset mock with usb_boot Enabled] ****************************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.024)       0:00:06.521 ********
ok: [instance]

TASK [Include bm_check_usb_boot] ***********************************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.274)       0:00:06.795 ********

TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.022)       0:00:06.817 ********
ok: [instance]

TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.274)       0:00:07.092 ********
ok: [instance]

TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.028)       0:00:07.121 ********
skipping: [instance]

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

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 19 March 2026  10:38:36 +0000 (0:00:00.027)       0:00:07.175 ********
ok: [instance]

TASK [Include bm_check_usb_boot (expect failure)] ******************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.291)       0:00:07.467 ********

TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.022)       0:00:07.489 ********
ok: [instance]

TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.274)       0:00:07.764 ********
ok: [instance]

TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.028)       0:00:07.792 ********
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [Assert failure was about GenericUsbBoot] *********************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.028)       0:00:07.821 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_ensure_usb_boot] *************************************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.020)       0:00:07.841 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_ensure_usb_boot.yml for instance

TASK [Reset mock with usb_boot Enabled and host Off] ***************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.030)       0:00:07.872 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot] **********************************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.278)       0:00:08.151 ********

TASK [bm_sno : Check current GenericUsbBoot state] *****************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.026)       0:00:08.178 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance

TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
Thursday 19 March 2026  10:38:37 +0000 (0:00:00.019)       0:00:08.197 ********
ok: [instance]

TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.274)       0:00:08.472 ********
ok: [instance]

TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.029)       0:00:08.502 ********
skipping: [instance]

TASK [Query mock state] ********************************************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.028)       0:00:08.530 ********
ok: [instance]

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

TASK [Reset mock with usb_boot Disabled and host Off] **************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.021)       0:00:08.824 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.278)       0:00:09.103 ********

TASK [bm_sno : Check current GenericUsbBoot state] *****************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.026)       0:00:09.129 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance

TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
Thursday 19 March 2026  10:38:38 +0000 (0:00:00.020)       0:00:09.150 ********
ok: [instance]

TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.279)       0:00:09.429 ********
ok: [instance]

TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.031)       0:00:09.461 ********
fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}

TASK [bm_sno : Fail if auto-enable is off] *************************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.030)       0:00:09.492 ********
skipping: [instance]

TASK [bm_sno : Set GenericUsbBoot BIOS attribute] ******************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.026)       0:00:09.518 ********
ok: [instance]

TASK [bm_sno : Create BIOS config job to schedule the change] ******************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.277)       0:00:09.795 ********
ok: [instance]

TASK [bm_sno : Power off before applying BIOS change] **************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.287)       0:00:10.082 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_off.yml for instance

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.022)       0:00:10.105 ********
ok: [instance]

TASK [bm_sno : Force power off via Redfish] ************************************
Thursday 19 March 2026  10:38:39 +0000 (0:00:00.278)       0:00:10.383 ********
skipping: [instance]

TASK [bm_sno : Wait for host to power off] *************************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.018)       0:00:10.402 ********
skipping: [instance]

TASK [bm_sno : Power on to apply BIOS config job during POST] ******************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.016)       0:00:10.418 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_on.yml for instance

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

TASK [bm_sno : Power on bare metal host] ***************************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.278)       0:00:10.723 ********
ok: [instance]

TASK [bm_sno : Wait for host POST to complete] *********************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.281)       0:00:11.004 ********
ok: [instance]

TASK [bm_sno : Show POST state] ************************************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.301)       0:00:11.306 ********
ok: [instance] => {
    "msg": "POST state: FinishedPost"
}

TASK [bm_sno : Power off after BIOS change applied] ****************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.028)       0:00:11.334 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_off.yml for instance

TASK [bm_sno : Query current power state] **************************************
Thursday 19 March 2026  10:38:40 +0000 (0:00:00.023)       0:00:11.358 ********
ok: [instance]

TASK [bm_sno : Force power off via Redfish] ************************************
Thursday 19 March 2026  10:38:41 +0000 (0:00:00.274)       0:00:11.633 ********
ok: [instance]

TASK [bm_sno : Wait for host to power off] *************************************
Thursday 19 March 2026  10:38:41 +0000 (0:00:00.278)       0:00:11.912 ********
ok: [instance]

TASK [Query mock state after auto-enable] **************************************
Thursday 19 March 2026  10:38:41 +0000 (0:00:00.292)       0:00:12.204 ********
ok: [instance]

TASK [Assert BIOS updated and host left Off] ***********************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.275)       0:00:12.479 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with usb_boot Disabled] ***************************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.021)       0:00:12.500 ********
ok: [instance]

TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.283)       0:00:12.784 ********

TASK [bm_sno : Check current GenericUsbBoot state] *****************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.026)       0:00:12.811 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance

TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.020)       0:00:12.831 ********
ok: [instance]

TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.277)       0:00:13.108 ********
ok: [instance]

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

TASK [bm_sno : Fail if auto-enable is off] *************************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.031)       0:00:13.170 ********
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 19 March 2026  10:38:42 +0000 (0:00:00.031)       0:00:13.201 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_eject_vmedia] ****************************************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.021)       0:00:13.223 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_eject_vmedia.yml for instance

TASK [Reset mock with VirtualMedia inserted] ***********************************
Thursday 19 March 2026  10:38:42 +0000 (0:00:00.031)       0:00:13.255 ********
ok: [instance]

TASK [Include bm_eject_vmedia] *************************************************
Thursday 19 March 2026  10:38:43 +0000 (0:00:00.277)       0:00:13.532 ********

TASK [bm_sno : Eject VirtualMedia] *********************************************
Thursday 19 March 2026  10:38:43 +0000 (0:00:00.023)       0:00:13.556 ********
ok: [instance]

TASK [bm_sno : Wait for VirtualMedia to report ejected] ************************
Thursday 19 March 2026  10:38:43 +0000 (0:00:00.270)       0:00:13.826 ********
ok: [instance]

TASK [bm_sno : Show VirtualMedia state after eject] ****************************
Thursday 19 March 2026  10:38:43 +0000 (0:00:00.291)       0:00:14.117 ********
ok: [instance] => {
    "msg": "VirtualMedia Inserted=False, Image="
}

TASK [Query mock state after eject] ********************************************
Thursday 19 March 2026  10:38:43 +0000 (0:00:00.032)       0:00:14.150 ********
ok: [instance]

TASK [Assert VirtualMedia is ejected] ******************************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.297)       0:00:14.447 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with VirtualMedia not inserted] *******************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.027)       0:00:14.475 ********
ok: [instance]

TASK [Include bm_eject_vmedia (idempotent)] ************************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.272)       0:00:14.747 ********

TASK [bm_sno : Eject VirtualMedia] *********************************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.023)       0:00:14.770 ********
ok: [instance]

TASK [bm_sno : Wait for VirtualMedia to report ejected] ************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.298)       0:00:15.069 ********
ok: [instance]

TASK [bm_sno : Show VirtualMedia state after eject] ****************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.285)       0:00:15.354 ********
ok: [instance] => {
    "msg": "VirtualMedia Inserted=False, Image="
}

TASK [Query mock state] ********************************************************
Thursday 19 March 2026  10:38:44 +0000 (0:00:00.031)       0:00:15.386 ********
ok: [instance]

TASK [Assert VirtualMedia is still not inserted] *******************************
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.270)       0:00:15.657 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Test bm_insert_vmedia] ***************************************************
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.028)       0:00:15.686 ********
included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_insert_vmedia.yml for instance

TASK [Reset mock with VirtualMedia ejected] ************************************
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.032)       0:00:15.719 ********
ok: [instance]

TASK [Include bm_insert_vmedia] ************************************************
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.293)       0:00:16.012 ********

TASK [bm_sno : Insert agent ISO via VirtualMedia] ******************************
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.024)       0:00:16.037 ********
ok: [instance]

TASK [bm_sno : Verify VirtualMedia reports inserted with correct image] ********
Thursday 19 March 2026  10:38:45 +0000 (0:00:00.278)       0:00:16.315 ********
ok: [instance]

TASK [bm_sno : Show VirtualMedia state after insert] ***************************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.280)       0:00:16.596 ********
ok: [instance] => {
    "msg": "VirtualMedia Inserted=True, Image=http://127.0.0.1:8080/agent.x86_64.iso"
}

TASK [Query mock state after insert] *******************************************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.032)       0:00:16.628 ********
ok: [instance]

TASK [Assert VirtualMedia is inserted with correct image] **********************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.262)       0:00:16.891 ********
ok: [instance] => {
    "changed": false,
    "msg": "All assertions passed"
}

TASK [Reset mock with a stale ISO already inserted] ****************************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.031)       0:00:16.922 ********
ok: [instance]

TASK [Include bm_insert_vmedia (expect failure)] *******************************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.276)       0:00:17.199 ********

TASK [bm_sno : Insert agent ISO via VirtualMedia] ******************************
Thursday 19 March 2026  10:38:46 +0000 (0:00:00.023)       0:00:17.222 ********
fatal: [instance]: FAILED! => {"attempts": 3, "changed": false, "content_length": "107", "content_type": "application/json", "date": "Thu, 19 Mar 2026 10:39:17 GMT", "elapsed": 0, "json": {"error": {"@Message.ExtendedInfo": [{"Message": "The Virtual Media image server is already connected."}]}}, "msg": "Status code was 400 and not [200, 204]: HTTP Error 400: Bad Request", "redirected": false, "server": "BaseHTTP/0.6 Python/3.9.25", "status": 400, "url": "https://localhost:8443/redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia"}
FAILED - RETRYING: [instance]: Insert agent ISO via VirtualMedia (3 retries left).
FAILED - RETRYING: [instance]: Insert agent ISO via VirtualMedia (2 retries left).
FAILED - RETRYING: [instance]: Insert agent ISO via VirtualMedia (1 retries left).

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

Thursday 19 March 2026  10:39:17 +0000 (0:00:31.077)       0:00:48.300 ********
===============================================================================
bm_sno : Insert agent ISO via VirtualMedia ----------------------------- 31.08s
Reset mock to power Off ------------------------------------------------- 0.39s
bm_sno : Wait for host POST to complete --------------------------------- 0.30s
bm_sno : Eject VirtualMedia --------------------------------------------- 0.30s
Query mock state after eject -------------------------------------------- 0.30s
Reset mock with VirtualMedia ejected ------------------------------------ 0.29s
bm_sno : Wait for host POST to complete --------------------------------- 0.29s
bm_sno : Wait for host to power off ------------------------------------- 0.29s
Reset mock with usb_boot Disabled --------------------------------------- 0.29s
bm_sno : Wait for VirtualMedia to report ejected ------------------------ 0.29s
Query mock state after power_on (no PostState) -------------------------- 0.29s
bm_sno : Create BIOS config job to schedule the change ------------------ 0.29s
bm_sno : Wait for VirtualMedia to report ejected ------------------------ 0.29s
Reset mock with usb_boot Disabled --------------------------------------- 0.28s
bm_sno : Power on bare metal host --------------------------------------- 0.28s
bm_sno : Verify VirtualMedia reports inserted with correct image -------- 0.28s
bm_sno : Wait for host POST to complete --------------------------------- 0.28s
bm_sno : Read GenericUsbBoot BIOS attribute ----------------------------- 0.28s
bm_sno : Wait for host POST to complete --------------------------------- 0.28s
bm_sno : Force power off via Redfish ------------------------------------ 0.28s

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

TASK [Stop mock iDRAC server] **************************************************
Thursday 19 March 2026  10:39:18 +0000 (0:00:00.020)       0:00:00.020 ********
ok: [instance]

TASK [Show mock server log] ****************************************************
Thursday 19 March 2026  10:39:18 +0000 (0:00:00.271)       0:00:00.292 ********
ok: [instance]

TASK [Print mock server log] ***************************************************
Thursday 19 March 2026  10:39:18 +0000 (0:00:00.179)       0:00:00.471 ********
ok: [instance] => {
    "_mock_log.stdout_lines": [
        "Mock iDRAC listening on https://0.0.0.0:8443",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
        "[mock-idrac] \"PATCH /redfish/v1/Systems/System.Embedded.1/Bios/Settings HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/Jobs HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.EjectMedia HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.EjectMedia HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia HTTP/1.1\" 204 -",
        "[mock-idrac] \"GET /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD HTTP/1.1\" 200 -",
        "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia HTTP/1.1\" 400 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia HTTP/1.1\" 400 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia HTTP/1.1\" 400 -",
        "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.InsertMedia HTTP/1.1\" 400 -"
    ]
}

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

Thursday 19 March 2026  10:39:18 +0000 (0:00:00.042)       0:00:00.513 ********
===============================================================================
Stop mock iDRAC server -------------------------------------------------- 0.27s
Show mock server log ---------------------------------------------------- 0.18s
Print mock server log --------------------------------------------------- 0.04s