BMCファームウェア16.5への更新がAlert: SPAutoUpgradeFailedMajorAlertで失敗する
環境
- AFF-A900、FAS9500
- BMC FWを16.3 -> 16.5から更新
問題
- BMC FWの自動更新は、ONTAP CLIおよびBMC CLI経由で失敗します。
SP rebootをtakeover/givebackSP daemon再起動しても、問題は解決されません。
::> set diagnostic; system node systemshell -node <node name>"sudo spmctl -s -h servprocd"
::> set diagnostic; system node systemshell -node <node name>"sudo spmctl -e -h servprocd"
- （BMC 16.5への）BMC FWの再ダウンロード後の手動更新も失敗します。
BMCの更新に失敗すると、次のログイベントが表示されます。
EMS log-event log show：
[servprocd: sp.servprocd.upd.evts:debug]: params: {'reason': 'SP Firmware network update has been successfully scheduled from 16.3 to 16.5'}
[servprocd: sp.servprocd.upd.evts:debug]: params: {'reason': 'SP Firmware network update from 16.3 to 16.5 has been triggered.'}
[servprocd: sp.servprocd.upd.unexpt.evts:debug]: params: {'reason': 'BMC update - BMC Firmware update failed.'}
[servprocd: sp.servprocd.upd.error:error]: SP update error: SP firmware update failure has been detected.- system health alert show log：
Node: ****
Monitor controller
Alert ID SPAutoUpgradeFailedMajorAlert
Alerting Resource SP Upgrade
Subsystem Service-Processor
Indication Time Wed Dec 27 12:00:10 2023
Perceived Severity Major
Probable Cause Configuration_error
Description A Service Processor automatic firmware update failure was detected, which can result in Service Processor not being updated to the latest available compatible firmware package.
Corrective Actions 1. Use the "system service-processor image show" command to display the firmware version that SP is currently booted from. 2. Manually upgrade Service Processor by using the "system service-processor image update" command. 3. Allow sufficient time for the system to update Service Processor firmware to the specified SP firmware package. 4. Contact the technical support if the alert persists.
Possible Effect Suboptimal system behavior can result from Service Processor not being updated to the latest available compatible firmware package.
Acknowledge false
Suppress false
Policy SPAutoUpgradeFailedMajorAlertPolicy
Acknowledger
Suppressor
Additional Information New firmware available: true New firmware Version : 16.5 Auto update: true Auto update Status: installed Previous AutoUpdate Status : failed
Alerting Resource Name SP Upgrade
Additional Alert Tags device
- MGWD.GZログ：
[kern_mgwd:info:8076] Dec 27 03:04:35: Software get http://.../SP_FW_308-04162_16.5.zip started on node ***
[kern_mgwd:info:8076] Dec 27 03:04:35: Downloading package. This may take up to 20 minutes.
[kern_mgwd:info:8076] HTTP/1.1 200 OK
[kern_mgwd:info:8076] Date: Wed, 27 Dec 2023 03:04:35 GMT
[kern_mgwd:info:8076] Server: Apache
[kern_mgwd:info:8076] Last-Modified: Wed, 27 Dec 2023 02:33:58 GMT
[kern_mgwd:info:8076] Accept-Ranges: bytes
[kern_mgwd:info:8076] Content-Length: 36757925
[kern_mgwd:info:8076] Content-Type: application/zip
[kern_mgwd:info:8076] 0x83ec7ac00: 0: DEBUG: PF_NDU::SoftwareImage: fetch:3334 package size: 35MB, mroot available: 2748987MB
[kern_mgwd:info:8076] Dec 27 03:04:35: 0% downloaded
[kern_mgwd:info:8076] Dec 27 03:04:35: 1% downloaded
...
[kern_mgwd:info:8076] Dec 27 03:04:36: 99% downloaded
[kern_mgwd:info:8076] Dec 27 03:04:36: 100% downloaded
[kern_mgwd:info:8076] Dec 27 03:04:36: Download complete.
[kern_mgwd:info:8076] Dec 27 03:04:36: Software get http://.../SP_FW_308-04162_16.5.zip completed on node- SP-MGMT-MLOG-TXT.GZログ：
00000023.00006d59 0006c8a1 Wed Dec 27 2023 11:55:04 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: InstallSpPckg: Removing /mroot/etc/RLM_FW
00000023.00006d5a 0006c8a1 Wed Dec 27 2023 11:55:04 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: InstallSpPckg: Installing /mroot/etc/software/SP_FW_308-04162_16.5.zip
00000023.00006d5c 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: InstallSpPckg: SP firmware package /mroot/etc/software/SP_FW_308-04162_16.5.zip has been installed.
00000023.00006d5d 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: ScheduleSpAutoUpdate: Checking whether SP network is available for SP firmware auto-update
00000023.00006d5e 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: ERR: Servprocd::SpUpdate: doPreUpdateChecks: In function - SpCPMIUpdateOp::doPreUpdateChecks()
00000023.00006d5f 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: doPreUpdateChecks: BMC update - Pre-update checks passed.
00000023.00006d60 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: ScheduleSpAutoUpdate: SP network auto-update has been successfully scheduled using firmware package /mroot/etc/software/SP_FW_308-04162_16.5.zip
00000023.00006d61 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: SpUpdateStateHandleEvent: SP update from version 16.3 to version 16.5 has been scheduled.
00000023.00006d62 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x808d5e400: 0: NOTICE: Servprocd::SpUpdate: UpdateSmfState: processing ck_auto_update_scheduled.
00000023.00006d63 0006c8a1 Wed Dec 27 2023 11:55:05 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: set_bmc_state_cpmi: updated BMC status - 8.
00000023.00006d64 0006c8d2 Wed Dec 27 2023 11:55:08 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: prepareImage: SP firmware image files were successfully checked for compression.
00000023.00006d65 0006c8d2 Wed Dec 27 2023 11:55:08 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: prepareImage: Creating /mroot/etc/RLM_FW/sp_image.tar.gz image for network transfer.
00000023.00006d6b 0006c8f7 Wed Dec 27 2023 11:55:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: prepareImage: /mroot/etc/RLM_FW/sp_image.tar.gz image has been successfully created for network transfer to SP.
00000023.00006d6c 0006c8f7 Wed Dec 27 2023 11:55:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: servprocd_trigger_fw_update_cpmi: cpmi_set_fw_update_info(16) suceeded.
00000023.00006d6d 0006c8f7 Wed Dec 27 2023 11:55:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: update: BMC update has been successfully triggered.
00000023.00006d70 0006ca23 Wed Dec 27 2023 11:55:42 +09:00 [kern_servprocd:info:50438] 0x809647900: 8503e800006239cf: NOTICE: Servprocd::CLI: get_spcs_port : spcs port value in sp_api_service mdb is 50000
00000023.00006d71 0006ca23 Wed Dec 27 2023 11:55:42 +09:00 [kern_servprocd:info:50438] 0x809648300: 8503e800006239cf: ERR: Servprocd::bmc_client: bmc_get_sensor_info_imp: target_node=***, err=entry doesn't exist
00000023.00006d72 0006ca23 Wed Dec 27 2023 11:55:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: Waiting for BMC update to complete. Monitor count=(0), sleep 30 seconds...
00000023.00006d73 0006ca23 Wed Dec 27 2023 11:55:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: lookup_bmc_updt_str: BMC update - Image download in progress.(0x4)
00000023.00006d7c 0006cb55 Wed Dec 27 2023 11:56:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: Waiting for BMC update to complete. Monitor count=(1), sleep 30 seconds...
00000023.00006d7d 0006cb55 Wed Dec 27 2023 11:56:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: lookup_bmc_updt_str: BMC update - Image download complete.(0x5)
00000023.00006d7f 0006cc7b Wed Dec 27 2023 11:56:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: Waiting for BMC update to complete. Monitor count=(2), sleep 30 seconds...
00000023.00006d80 0006cc7b Wed Dec 27 2023 11:56:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: lookup_bmc_updt_str: BMC update - Image download in progress.(0x4)
00000023.00006d86 0006cdac Wed Dec 27 2023 11:57:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: Waiting for BMC update to complete. Monitor count=(3), sleep 30 seconds...
00000023.00006d87 0006cdac Wed Dec 27 2023 11:57:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: lookup_bmc_updt_str: BMC update - Image download complete.(0x5)
00000023.00006d8b 0006ced3 Wed Dec 27 2023 11:57:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: Waiting for BMC update to complete. Monitor count=(4), sleep 30 seconds...
00000023.00006d8c 0006ced3 Wed Dec 27 2023 11:57:43 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: lookup_bmc_updt_str: BMC update - Unknown error.(0xa5)
00000023.00006d93 0006cfff Wed Dec 27 2023 11:58:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: monitorUpdate: BMC update has failed. Last status code(165).
00000023.00006d94 0006cfff Wed Dec 27 2023 11:58:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: set_bmc_state_cpmi: updated BMC status - 1.
00000023.00006d95 0006cfff Wed Dec 27 2023 11:58:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: ERR: Servprocd::SpUpdate: SpUpdateStateHandleEvent: e_sp_update_failed event received in SP_UPDATE_IN_PROGRESS state.
00000023.00006d96 0006cfff Wed Dec 27 2023 11:58:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: ERR: Servprocd::SpUpdate: SpUpdateReport: SP firmware update failure has been detected.
00000023.00006d97 0006cfff Wed Dec 27 2023 11:58:13 +09:00 [kern_servprocd:info:50438] 0x809747500: 0: NOTICE: Servprocd::SpUpdate: UpdateSmfState: processing upd_stat 9 event.
00000023.00006da2 0006d11e Wed Dec 27 2023 11:58:41 +09:00 [kern_servprocd:info:50438] 0x809648300: 8503e80000623a6d: NOTICE: Servprocd::CLI: get_spcs_port : spcs port value in sp_api_service mdb is 50000
00000023.00006da3 0006d11e Wed Dec 27 2023 11:58:42 +09:00 [kern_servprocd:info:50438] 0x809649200: 8503e80000623a6d: ERR: Servprocd::bmc_client: bmc_get_sensor_info_imp: target_node=***, err=entry doesn't exist
00000023.00006dba 0006d828 Wed Dec 27 2023 12:01:41 +09:00 [kern_servprocd:info:50438] 0x809648800: 8503e80000623afe: NOTICE: Servprocd::CLI: get_spcs_port : spcs port value in sp_api_service mdb is 50000
00000023.00006dbb 0006d828 Wed Dec 27 2023 12:01:42 +09:00 [kern_servprocd:info:50438] 0x809647900: 8503e80000623afe: ERR: Servprocd::bmc_client: bmc_get_sensor_info_imp: target_node=***, err=entry doesn't exist
00000023.00006df1 0006db4c Wed Dec 27 2023 12:03:03 +09:00 [kern_servprocd:info:50438] 0x808d5ee00: 0: NOTICE: Servprocd::SpUpdate: SpUpdateStateHandleEvent: e_sp_online event received in SP_UPDATE_NOT_IN_PROGRESS state.