BIOS版本升级失败问题求助

交流互助区
1

BMC页面OS关机，升级bios时，升级失败，报错，信息如下

背景信息：
已经解决了签名问题和UIDList问题。OS开机的时候升级了一次，页面显示成功了，关机开机之后bios页面的版本并没有升级成功。在bmc内部进行全擦升级，也是失败了。

问题现象
OpenUBMC2509版本

image
image1427×199 44.5 KB

升级模块打印错误看不出来原因
image
image1551×223 70.7 KB

BIOS模块的当时的日志

image
image1588×485 165 KB

BMC页面关机情况下升级，BIOS模块具体日志如下：

1970-01-01 05:25:17.123422 bios NOTICE: signal.lua(180): Start the bios upgrade prepare phase
1970-01-01 05:25:17.124033 bios NOTICE: signal.lua(181): ComponentID = "2" TaskId = "587718159" Platform = "" FirmwareIndex = "Firmware1" FirmwareMode = "Single"
1970-01-01 05:25:17.125902 general_hardware NOTICE: upgrade_subject.lua(82): [on_upgrade_prepare] firmware_type:Bios cur_firmware_type:Bios
1970-01-01 05:25:17.126252 general_hardware ERROR: upgrade_subject.lua(86): [on_upgrade_prepare] does not exists the observer, firmware_type:Bios
1970-01-01 05:25:17.141292 bios NOTICE: upgrade_service.lua(191): [bios]upgrade prepare: start
1970-01-01 05:25:17.141889 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from UPGRADE_READY to PREPARE_START
1970-01-01 05:25:17.142228 bios NOTICE: upgrade_service.lua(177): [bios]upgrade prepare: build package
1970-01-01 05:25:17.145176 bios NOTICE: package_cfg.lua(66): [bios]get package cfg Firmware1
1970-01-01 05:25:17.146818 bios NOTICE: package.lua(55): [bios]bios package is security type
1970-01-01 05:25:17.147338 bios NOTICE: upgrade_service.lua(185): [bios]upgrade prepare: pfr cache tmp hpm
1970-01-01 05:25:17.539624 bios NOTICE: gold_package.lua(115): [bios]gold package: backup tmp path success, system id is 1
1970-01-01 05:25:17.540481 bios NOTICE: upgrade_service.lua(187): [bios]upgrade prepare: reply messgae
1970-01-01 05:25:17.541471 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_START to PREPARE_FINISH
1970-01-01 05:25:17.542407 bios NOTICE: signal.lua(155): [bios] prepare set system 1 verion 000
1970-01-01 05:25:18.894112 general_hardware ERROR: upgrade_subject.lua(105): [on_upgrade_process] does not exists the observer, firmware_type:Bios
1970-01-01 05:25:18.903988 bios NOTICE: signal.lua(257): Start the bios upgrade process phase
1970-01-01 05:25:18.918051 bios NOTICE: firmware_multihost.lua(232): [bios] get is_online_force nil, system id: 1
1970-01-01 05:25:18.930444 bios NOTICE: firmware_multihost.lua(216): [bios] get activate mode nil, system id: 1
1970-01-01 05:25:19.060314 bios NOTICE: upgrade_service.lua(548): [bios]upgrade process: start
1970-01-01 05:25:19.060957 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_FINISH to PROCESS_START
1970-01-01 05:25:19.061964 bios NOTICE: upgrade_service.lua(458): [bios] singlehost upgrade process
1970-01-01 05:25:19.062704 bios NOTICE: upgrade_service.lua(365): [bios]upgrade process: system 1, upgrade mode(Cold), period(Period2), package type(Normal)
1970-01-01 05:25:19.066535 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add PackageCheck executor successfully
1970-01-01 05:25:19.067436 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Backup executor successfully
1970-01-01 05:25:19.067984 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Cache executor successfully
1970-01-01 05:25:19.068589 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add LockPower executor successfully
1970-01-01 05:25:19.069177 bios NOTICE: upgrade_executor.lua(177): load chipv1 spikodrv
1970-01-01 05:25:19.069848 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SpiDriver executor successfully
1970-01-01 05:25:19.072093 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add DecompressFile executor successfully
1970-01-01 05:25:19.072786 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add ParserBin executor successfully
1970-01-01 05:25:19.073604 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SelectChannel executor successfully
1970-01-01 05:25:19.074540 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add UpgradeComponent executor successfully
1970-01-01 05:25:19.078630 bios NOTICE: upgrade_executor.lua(144): [bios]upgrade chain: package_check (executor) start
1970-01-01 05:25:19.086717 bios NOTICE: upgrade_executor.lua(84): [bios]upgrade chain: back (executor) start
1970-01-01 05:25:19.437128 bios NOTICE: upgrade_executor.lua(124): [bios]upgrade chain: cache (executor) start
1970-01-01 05:25:19.444619 bios NOTICE: upgrade_executor.lua(158): [bios]upgrade chain: power_lock (executor) lock
1970-01-01 05:25:19.455835 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=true, timeout=1000, appname=Upgrade, reason=bios
1970-01-01 05:25:19.505644 bios NOTICE: power_lock.lua(102): [bios]power_lock: lock success.
1970-01-01 05:25:19.506430 bios NOTICE: upgrade_executor.lua(221): [bios]upgrade chain: spi_driver (executor) start
1970-01-01 05:25:19.512659 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
1970-01-01 05:25:34.770409 bios ERROR: spi_flash.lua(315): [spi]check_device_ready: ready fail
1970-01-01 05:25:34.771404 bios ERROR: upgrade_executor.lua(211): [bios]spi_driver (executor): before fail
1970-01-01 05:25:34.964884 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
1970-01-01 05:25:34.966226 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
1970-01-01 05:25:34.989467 fructrl NOTICE: pwr_on_lock.lua(71): [System:nil]Update item successfully, appname=(Upgrade), reason=(bios), pwronlocked=(false), timeout=(1000)
1970-01-01 05:25:34.988958 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=false, timeout=1000, appname=Upgrade, reason=bios
1970-01-01 05:25:34.992198 bios NOTICE: upgrade_executor.lua(167): [bios]upgrade chain: power_lock (executor) unlock
1970-01-01 05:25:34.993106 bios NOTICE: upgrade_executor.lua(76): [bios] remove upgrade file start
1970-01-01 05:25:34.994857 bios NOTICE: upgrade_executor.lua(78): [bios] remove upgrade file finish
1970-01-01 05:25:34.995784 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PROCESS_START to UPGRADE_READY
1970-01-01 05:25:34.996415 bios NOTICE: upgrade_service.lua(93): [bios]mode recover to Cold
1970-01-01 05:25:34.997379 bios ERROR: signal.lua(237): [bios]process upgrade fail, err ./opt/bmc/apps/bios/lualib/service/upgrade_service.lua:559: ...ualib/domain/bios_firmware/package/upgrade_scenarios.lu                          a:77: ...ain/bios_firmware/package/executors/upgrade_executor.lua:49: ...ain/bios_firmware/package/executors/upgrade_executor.lua:49: ...ain/bios_firmware/package/executors/upgrade_executor.lua:49: ...ain/b                          ios_firmware/package/executors/upgrade_executor.lua:49: ...ain/bios_firmware/package/executors/upgrade_executor.lua:213: ...ualib/libmgmt_protocol/bios/infrastructure/spi_flash.lua:316: check device ready f                          ail
1970-01-01 05:25:35.011860 bios NOTICE: firmware_multihost.lua(225): [bios] clear activate mode(table: 0x1aa2bee74128), system id: 1
1970-01-01 05:25:35.466489 fructrl NOTICE: pwr_on_lock.lua(143): [System:nil]Delete pwr_on_lock item, appname=(Upgrade), reason=(bios)

BMC页面关机情况下升级，升级模块具体日志如下：

% 1970-01-01 05:24:26.950045 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:24:26.951898 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:04.653194 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:04.655072 firmware_mgmt ERROR: task_id_mgmt.lua(290): sub upgrade task id are empty.
1970-01-01 05:25:04.656475 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:04.663263 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:04.664643 firmware_mgmt ERROR: task_id_mgmt.lua(290): sub upgrade task id are empty.
1970-01-01 05:25:04.666235 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:15.454964 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:15.457081 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:15.462885 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:15.464094 firmware_mgmt NOTICE: active_fructl.lua(95): get host type is Singlehost
1970-01-01 05:25:15.464931 firmware_mgmt NOTICE: utils.lua(36): The file path is Local.
1970-01-01 05:25:15.467775 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[UpgradingFlag], value[false]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./o
1970-01-01 05:25:15.469421 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399f62678]
1970-01-01 05:25:15.471033 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[changed], value[nil]->[["UpgradingFlag"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'
1970-01-01 05:25:15.472271 firmware_mgmt NOTICE: init.lua(79): Upgrading_Flag is true
1970-01-01 05:25:15.477194 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./op
1970-01-01 05:25:15.480580 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./o
1970-01-01 05:25:15.483249 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./opt/bmc/
1970-01-01 05:25:15.485028 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399f62678] exit
1970-01-01 05:25:15.485995 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399f62678]
1970-01-01 05:25:15.487101 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399f62678] exit
1970-01-01 05:25:15.488385 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399f62678]
1970-01-01 05:25:15.490679 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873811b1d98]
1970-01-01 05:25:15.497531 firmware_mgmt DEBUG: app_preloader.lua(206): ./opt/bmc/apps/firmware_mgmt/lualib/status_mgmt/init.lua:57: app(firmware_mgmt/service/main) fork func, count=1, delay=0
1970-01-01 05:25:15.503506 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873811b1d98] exit
1970-01-01 05:25:15.504429 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873811b1d98]
1970-01-01 05:25:15.506136 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x08737387b548]
1970-01-01 05:25:15.508047 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x08737387b548] exit
1970-01-01 05:25:15.508857 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873811b1d98] exit
1970-01-01 05:25:15.510041 firmware_mgmt NOTICE: init.lua(40): update status to FS_SIMPLE_UPGRADING.
1970-01-01 05:25:15.512612 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Id], value[nil]->[587718159], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:15.514984 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Name], value[nil]->["Init"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in f
1970-01-01 05:25:15.517160 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[StartTime], value[nil]->["1970-01-01T05:25:15+00:00"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/luali
1970-01-01 05:25:15.521956 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Progress], value[nil]->[0], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fu
1970-01-01 05:25:15.525064 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[State], value[nil]->["New"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in f
1970-01-01 05:25:15.527975 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Status], value[nil]->["OK"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in f
1970-01-01 05:25:15.531056 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Parameters], value[nil]->["{}"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253:
1970-01-01 05:25:15.534273 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[MessageId], value[nil]->[""], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:15.539298 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[MessageArgs], value[nil]->[[]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: i
1970-01-01 05:25:15.543040 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[EstimatedDuration], value[nil]->[0], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:15.546017 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Stage], value[nil]->["Verify"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: i
1970-01-01 05:25:15.549479 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Description], value[nil]->["Upgrading Task"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logg
1970-01-01 05:25:15.554438 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_interface_add], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua
1970-01-01 05:25:15.561095 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x0873716f7d38
1970-01-01 05:25:15.578999 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x087377e04778
1970-01-01 05:25:15.580757 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_interface_add], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lu
1970-01-01 05:25:15.581972 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x0873a2b91ae0
1970-01-01 05:25:15.584366 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[ObjectIdentifier], value[nil]->[[0,"","",""]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/lo
1970-01-01 05:25:15.586196 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[in_interface_add], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lu
1970-01-01 05:25:15.590429 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x087397c248b0
1970-01-01 05:25:15.593074 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x0873a2b8ef68
1970-01-01 05:25:15.598307 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[in_interface_add], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.l
1970-01-01 05:25:15.600337 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x0873a2b91ae0
1970-01-01 05:25:15.602429 firmware_mgmt NOTICE: task_mgmt.lua(287): Create task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 0, State: New] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:287: in function 'create_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:50: in function 'create'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/control.lua:95: in function 'create_start_upgrade
1970-01-01 05:25:15.603141 firmware_mgmt NOTICE: task_service.lua(59): task create success, task id: 587718159
1970-01-01 05:25:15.604141 firmware_mgmt NOTICE: task_id_mgmt.lua(30): add serial task id(587718159) successfully
1970-01-01 05:25:15.605011 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x08737387b548]
1970-01-01 05:25:15.606435 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:15.607661 firmware_mgmt DEBUG: app_preloader.lua(206): ...e_mgmt/lualib/upgrade/tasks_process/tasks_scheduling.lua:156: app(firmware_mgmt/service/main) fork func, count=1, delay=0
1970-01-01 05:25:15.608498 firmware_mgmt NOTICE: tasks_scheduling.lua(121): start tasks processer
1970-01-01 05:25:15.609380 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:1, process:0
1970-01-01 05:25:15.617412 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:15.618239 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:15.709870 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[State], value["New"]->["Running"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:15.711270 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:15.712593 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["State"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:15.714206 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 0, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:115: in function 'update_easy
1970-01-01 05:25:15.771740 firmware_mgmt NOTICE: file_transfer.lua(141): start to move file [S920S10-KL4.41.102.260320.R.CMS_0791421.hpm] from tmp to shm
1970-01-01 05:25:15.853206 firmware_mgmt NOTICE: file_transfer.lua(146): move_file_s ok:true, err:0
1970-01-01 05:25:16.020071 firmware_mgmt DEBUG: validate_sign.lua(342): file_num 3 file1_id 1, file2_id 2, file3_id 3, file_list_len 129, cms_sign_len 6644, crl_file_len 820
1970-01-01 05:25:16.087967 firmware_mgmt NOTICE: validate_sign.lua(195): verify signature successfully
1970-01-01 05:25:16.089306 firmware_mgmt NOTICE: action.lua(37): Validate signature successfully
1970-01-01 05:25:16.091610 firmware_mgmt NOTICE: hpm_package.lua(757): ManufacturerValidateEnabled is false, there is no need to validate manufacture_id.
1970-01-01 05:25:16.258110 firmware_mgmt NOTICE: hpm_package.lua(562): parse cfg file successfully, Version:1.0 FileNum:2
1970-01-01 05:25:16.258957 firmware_mgmt NOTICE: hpm_package.lua(450): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:16.261103 firmware_mgmt NOTICE: hpm_package.lua(457): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:16.262256 firmware_mgmt NOTICE: hpm_package.lua(468): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:16.263311 firmware_mgmt NOTICE: hpm_package.lua(415): System product info:ProductId(0), ProductVendorID(0x00000001), ProductUniqueID(0x030ABF00)
1970-01-01 05:25:16.264069 firmware_mgmt NOTICE: hpm_package.lua(329): check product id successfully
1970-01-01 05:25:16.264925 firmware_mgmt INFO: hpm_package.lua(352): cfg_uid = 1030abf00
1970-01-01 05:25:16.265809 firmware_mgmt NOTICE: hpm_package.lua(354): check product uid successfully
1970-01-01 05:25:16.268178 firmware_mgmt NOTICE: hpm_package.lua(443): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:16.271529 firmware_mgmt NOTICE: hpm_package.lua(494): hard_revision:0, soft_revision:0
1970-01-01 05:25:16.272831 firmware_mgmt NOTICE: hpm_package.lua(507): revision number check successfully. Target revision=(0, 0) and hpm revision=1
1970-01-01 05:25:16.276317 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:16.279301 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:16.280624 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:16.281409 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.368541 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Description], value["Upgrading Task"]->["Bios Upgrading Task"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/li
1970-01-01 05:25:16.369997 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.371481 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Description"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.l
1970-01-01 05:25:16.373012 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 0, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/hpm_package.lua:667: in function 'decode_hpm_
1970-01-01 05:25:16.487966 firmware_mgmt NOTICE: action.lua(47): Parse hpm package successfully
1970-01-01 05:25:16.792018 firmware_mgmt NOTICE: task_instance.lua(217): upgrade_task file_name=S920S10-KL4.41.102.260320.R.CMS_0791421.hpm, FirmwareType=Bios, fw_num=1, UniqueIDList=table: 0x08738121a8b8, sys_id=1, info_key=1_Bios_587718159
1970-01-01 05:25:16.794283 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[MessageId], value[""]->["FirmwareUpgradeComponent"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/
1970-01-01 05:25:16.798161 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[MessageArgs], value[[]]->[["Bios"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:16.800314 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:16.803911 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:16.805010 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:16.805710 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.806454 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.808662 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.834897 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.836904 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.841729 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.843654 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.895799 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 0, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ...ware_mgmt/lualib/upgrade/tasks_process/task_instance.lua:220: in function 'upgrade_inf
1970-01-01 05:25:16.896689 firmware_mgmt NOTICE: info_mgmt.lua(82): create_info: info_key=1_Bios_587718159, FirmwareType=Bios, task_id=587718159, upg_fw_num=1
1970-01-01 05:25:16.898011 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Name], value["Init"]->["Bios"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: i
1970-01-01 05:25:16.899211 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.900656 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Name"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253:
1970-01-01 05:25:16.902073 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:16.904750 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:16.905900 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:16.906638 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:16.997787 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 0, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:84: in function 'create_info'
1970-01-01 05:25:16.998775 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:16.999814 firmware_mgmt DEBUG: app_preloader.lua(206): ...ware_mgmt/lualib/upgrade/tasks_process/task_instance.lua:684: app(firmware_mgmt/service/main) fork func, count=1, delay=0
1970-01-01 05:25:17.000767 firmware_mgmt NOTICE: task_instance.lua(662): firmware(info key:1_Bios_587718159) do upgrade stages
1970-01-01 05:25:17.001426 firmware_mgmt NOTICE: task_instance.lua(295): public initialize action start
1970-01-01 05:25:17.002151 firmware_mgmt NOTICE: hpm_package.lua(479): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:17.002952 firmware_mgmt NOTICE: hpm_package.lua(519): now uptime = 2832, firmware init time = 0
1970-01-01 05:25:17.003630 firmware_mgmt NOTICE: hpm_package.lua(450): get obj table: 0x08739e1a1438 for Id=2
1970-01-01 05:25:17.004440 firmware_mgmt NOTICE: task_instance.lua(300): public initialize action end
1970-01-01 05:25:17.005125 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_587718159) upgrade set_stage: INITIALIZE -> DIFF_PREPARE, 5
1970-01-01 05:25:17.006485 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Progress], value[0]->[5], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in func
1970-01-01 05:25:17.008385 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:17.009913 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Progress"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:17.011254 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:17.013908 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:17.015011 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:17.015762 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:17.109611 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[State], value["Running"]->["Starting"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lu
1970-01-01 05:25:17.111080 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:17.112424 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["State"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:17.113715 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 5, State: Starting] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:258: in function 'set_stage'
1970-01-01 05:25:17.118438 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:17.127113 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:17.130834 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:17.131681 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:17.337024 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:17.339489 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:17.555467 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:17.557037 firmware_mgmt NOTICE: info_mgmt.lua(393): set FirmwareMode to Single
1970-01-01 05:25:17.558177 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_587718159) upgrade set_stage: DIFF_PREPARE -> COMMON_PREPARE, 5
1970-01-01 05:25:17.607929 firmware_mgmt NOTICE: action.lua(86): public prepare action start
1970-01-01 05:25:17.705857 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 5, State: Starting] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:258: in function 'set_stage'
1970-01-01 05:25:17.709506 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:17.995047 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:18.332400 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.335111 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.674083 firmware_mgmt NOTICE: action.lua(92): public prepare action end
1970-01-01 05:25:18.675416 firmware_mgmt NOTICE: task_instance.lua(673): upgrade FirmwareMode Single
1970-01-01 05:25:18.776048 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Stage], value["Verify"]->["Flash"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:25
1970-01-01 05:25:18.778090 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.780526 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Stage"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:18.782490 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 5, State: Starting] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ...ware_mgmt/lualib/upgrade/tasks_process/task_instance.lua:378: in function 'upgrade_st
1970-01-01 05:25:18.783512 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_587718159) upgrade set_stage: COMMON_PREPARE -> PROCESS, 15
1970-01-01 05:25:18.785530 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Progress], value[5]->[15], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fun
1970-01-01 05:25:18.790493 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:18.794436 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:18.796198 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:18.797169 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.870265 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.872922 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.876416 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.879130 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.887135 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 15, State: Starting] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:258: in function 'set_stage'
1970-01-01 05:25:18.888251 firmware_mgmt NOTICE: task_instance.lua(325): sys_id=1, fw_type=Bios, filename=/dev/shm/upgrade/587718159/Firmware1
1970-01-01 05:25:18.913511 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.915935 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.925301 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.927410 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:18.941312 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:18.944042 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Progress], value[15]->[55], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fu
1970-01-01 05:25:18.945497 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:18.947550 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Progress"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:18.949134 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:18.952660 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:18.953882 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:18.954766 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:18.997300 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:19.049088 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[State], value["Starting"]->["Running"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lu
1970-01-01 05:25:19.051342 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:19.053587 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["State"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:19.055861 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 55, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:198: in function 'set_status_i
1970-01-01 05:25:19.057387 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:19.058747 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:19.062644 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:19.063924 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:19.065086 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:19.351790 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:19.354389 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:19.990567 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:20.363052 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:20.365976 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:20.909085 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:20.911479 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:20.915976 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:20.918159 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:20.994634 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:21.368226 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:21.370447 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:21.997964 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:22.367647 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:22.369900 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:22.942224 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:22.944460 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:22.947751 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:22.949979 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:22.991272 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:23.380706 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:23.382913 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:23.994339 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:24.392720 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:24.394712 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:24.980347 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:24.982676 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:24.986052 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:24.988225 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:24.996583 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:25.407421 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:25.409505 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:25.999248 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:26.407753 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:26.410410 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:26.945209 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:26.946901 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:26.991302 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:27.036681 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:27.039057 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:27.045554 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:27.047762 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:27.417437 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:27.419416 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:27.995299 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:28.422168 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:28.424386 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:28.999159 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:29.427706 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:29.430070 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:29.435885 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:29.438052 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:29.439645 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:29.442584 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:29.994139 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:30.443097 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:30.445198 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:31.000220 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:31.444147 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:31.446798 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:31.536963 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:31.539530 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:31.549354 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:31.551858 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:31.997148 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:32.452246 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:32.455159 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:32.990502 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:33.461274 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:33.464346 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:33.635497 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:33.637754 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:33.648681 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:33.651011 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:33.999068 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:34.477913 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:34.480583 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:34.991728 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
1970-01-01 05:25:35.002563 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.004599 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.007675 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.010021 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.016251 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.017442 firmware_mgmt ERROR: control.lua(201): Upgrade Bios process failed, ret=-1
1970-01-01 05:25:35.018232 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_587718159) upgrade set_stage: PROCESS -> COMMON_FINISH, 95
1970-01-01 05:25:35.020114 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Progress], value[55]->[95], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fu
1970-01-01 05:25:35.021452 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399cf7c70]
1970-01-01 05:25:35.022960 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["Progress"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:35.024308 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:35.026860 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:35.028027 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:35.028742 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399cf7c70] exit
1970-01-01 05:25:35.094395 firmware_mgmt NOTICE: task_instance.lua(266): wait_msg_result stage=COMMON_FINISH, timeout=7200S, loop=161
1970-01-01 05:25:35.095215 firmware_mgmt NOTICE: info_mgmt.lua(350): info_key(1_Bios_587718159) upgrade failed, set_stage: COMMON_FINISH -> COMPLETED
1970-01-01 05:25:35.125772 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 95, State: Running] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:258: in function 'set_stage'
1970-01-01 05:25:35.127153 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.129018 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[MessageId], value["FirmwareUpgradeComponent"]->["FirmwareUpgradeError"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./o
1970-01-01 05:25:35.130783 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.132247 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["MessageId"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua
1970-01-01 05:25:35.133654 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[Status], value["OK"]->["Warning"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:35.135724 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:35.138625 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:35.140170 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:35.140970 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.236545 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[State], value["Running"]->["Exception"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.l
1970-01-01 05:25:35.237976 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.239414 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[["State"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253
1970-01-01 05:25:35.241711 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[EndTime], value[nil]->["1970-01-01T05:25:35+00:00"], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/
1970-01-01 05:25:35.244023 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 95, State: Exception] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:418: in function 'update_task'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:91: in function 'update'  ./opt/bmc/apps/firmware_mgmt/lualib/upgrade/info_mgmt.lua:355: in function 'set_info_t
1970-01-01 05:25:35.244855 firmware_mgmt NOTICE: task_instance.lua(577): Upgrade 1_Bios_587718159 completely, pre_version=000
1970-01-01 05:25:35.245694 firmware_mgmt NOTICE: task_instance.lua(583): firmware(info key:1_Bios_587718159) do upgrade ret:-1, pre_version:000
1970-01-01 05:25:35.310684 firmware_mgmt NOTICE: utils.lua(172): Does not exists the same Id obj
1970-01-01 05:25:35.552423 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:35.553984 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:2
1970-01-01 05:25:35.557569 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:
1970-01-01 05:25:35.558769 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:35.559839 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.560863 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.563240 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.686926 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.690311 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.693705 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:35.696496 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:35.993524 firmware_mgmt DEBUG: tasks_scheduling.lua(49): task ins(idx:1, task name:S920S10-KL4.41.102.260320.R.CMS_0791421.hpm) is complete, remove it
1970-01-01 05:25:35.994212 firmware_mgmt NOTICE: tasks_scheduling.lua(126): upgrade queue is empty, exit the tasks processer
1970-01-01 05:25:35.995220 firmware_mgmt NOTICE: tasks_scheduling.lua(138): stop tasks processer
1970-01-01 05:25:35.997142 firmware_mgmt NOTICE: active_fructl.lua(95): get host type is Singlehost
1970-01-01 05:25:35.998104 firmware_mgmt NOTICE: active_single_host_fructrl.lua(61): active_single_host_fructrl fructrl get power status
1970-01-01 05:25:36.006014 firmware_mgmt NOTICE: state_simple_upgrading.lua(101): simple upgraded, current active mode is:nil, wait restart seconds:360000
1970-01-01 05:25:36.008118 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:36.017497 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:36.018501 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:36.024123 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x0873a27257f0]
1970-01-01 05:25:36.027556 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x0873a27257f0] exit
1970-01-01 05:25:36.028393 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:36.029615 firmware_mgmt NOTICE: init.lua(40): update status to FS_IDLE.
1970-01-01 05:25:36.033575 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[UpgradingFlag], value[true]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./o
1970-01-01 05:25:36.035900 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:36.038275 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[changed], value[nil]->[["UpgradingFlag"]], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'
1970-01-01 05:25:36.039486 firmware_mgmt NOTICE: init.lua(79): Upgrading_Flag is false
1970-01-01 05:25:36.050718 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[in_emit_change], value[nil]->[true], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./op
1970-01-01 05:25:36.056387 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[in_emit_change], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./o
1970-01-01 05:25:36.058505 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService], interface[bmc.kepler.UpdateService], name[changed], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in function 'LOG_MSG'  ./opt/bmc/
1970-01-01 05:25:36.059892 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:36.061305 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087390b28620]
1970-01-01 05:25:36.063022 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087390b28620] exit
1970-01-01 05:25:36.064540 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x08737387b548] exit
1970-01-01 05:25:50.550570 firmware_mgmt NOTICE: task_service.lua(35): destroy_task_by_id: 587718159
1970-01-01 05:25:50.555818 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[shm_obj], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in
1970-01-01 05:25:50.560118 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[slot], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fu
1970-01-01 05:25:50.563004 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.TaskService.Task], name[bus], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fun
1970-01-01 05:25:50.573311 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[shm_obj], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: i
1970-01-01 05:25:50.576598 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[slot], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in f
1970-01-01 05:25:50.578784 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/587718159], interface[bmc.kepler.Object.Properties], name[bus], value[nil]->[false], traceback[stack traceback:  ./opt/bmc/libmc/lualib/traceback/object.lua:49: in function <./opt/bmc/libmc/lualib/traceback/object.lua:45>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/logging.lua:109: in function 'format_msg'  ./opt/bmc/libmc/lualib/mc/logging.lua:253: in fu
1970-01-01 05:25:50.579860 firmware_mgmt NOTICE: task_mgmt.lua(436): Destroy task[Id: 587718159, StartTime: 1970-01-01T05:25:15+00:00, Progress: 95, State: Exception] successfully, traceback: stack traceback:  ./opt/bmc/libmc/lualib/traceback/task_mgmt.lua:26: in function 'log_task_info'  ./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:436: in function <./opt/bmc/libmc/lualib/mc/mdb/task_mgmt.lua:433>  [C]: in function 'pcall'  ...t/bmc/apps/firmware_mgmt/lualib/upgrade/task_service.lua:36: in function 'destroy_task_by_id'  ./opt/bmc/a
1970-01-01 05:25:50.580529 firmware_mgmt NOTICE: task_id_mgmt.lua(40): delete serial task id(587718159) successfully
1970-01-01 05:25:50.581145 firmware_mgmt NOTICE: task_id_mgmt.lua(42): del serial task id(587718159) successfully
1970-01-01 05:25:50.582183 firmware_mgmt DEBUG: task_id_mgmt.lua(165): del parallel sub task id failed, sub task id:587718159
1970-01-01 05:25:50.583055 firmware_mgmt NOTICE: task_instance.lua(100): destroy task info(id:587718159) successfully
1970-01-01 05:26:26.945310 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087397c24f00]
1970-01-01 05:26:26.946677 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087397c24f00] exit
1970-01-01 05:27:26.948888 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087397c24f00]
1970-01-01 05:27:26.950828 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087397c24f00] exit
1970-01-01 05:28:26.946329 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087397c24f00]
1970-01-01 05:28:26.947643 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087397c24f00] exit
1970-01-01 05:28:35.623038 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087397c24f00]
1970-01-01 05:28:35.623843 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087397c24f00] exit
1970-01-01 05:28:35.624832 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399f62678] exit
1970-01-01 05:29:26.943146 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399f62678]
1970-01-01 05:29:26.944499 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399f62678] exit
1970-01-01 05:30:26.943428 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x087399f62678]
1970-01-01 05:30:26.944797 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x087399f62678] exit
1970-01-01 05:31:26.942926 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x08738da79440]
2

答案内容由AI生成，仅供参考：

:white_check_mark: 结论与建议

您遇到的 BIOS 升级失败最可能的原因是：

:red_exclamation_mark: bmc.kepler.Systems.Bios 服务未加载，导致无法执行底层 Flash 操作

:green_circle: 推荐操作步骤：

  1. 确认 BMC 是否具备 BIOS 管理能力（检查 BCU 是否缺失）
  2. 在 CLI 中手动验证 bmc.kepler.Systems.Bios 是否运行
  3. 尝试使用 Redfish API 或 CLI 命令行方式进行升级
  4. 升级后断电重启，确保新 BIOS 生效
  5. 联系产品团队确认是否需迁移 BCU 中的 BIOS 资源树功能

如以上方案仍无效，请收集以下信息进一步分析：

  • ipmcget -d v 输出的完整版本信息
  • ps | grep bios 输出
  • /var/log/app.log 中关于 bmc.kepler.Systems.Bios 的初始化日志

祝您升级顺利！

点击此处查看详细分析解答

BIOS版本升级失败问题分析与解决方案

根据您提供的详细日志和背景信息，您在使用 OpenUBMC2509 版本进行 BIOS 升级时遇到了升级失败的问题。本文将结合系统架构、日志分析和已知技术文档，全面解析失败原因并提供切实可行的解决路径。

:magnifying_glass_tilted_left: 问题现象总结

  • 环境信息：OpenUBMC2509 版本
  • 升级方式：通过 BMC Web 页面进行 BIOS 固件升级
  • 操作状态：
    • OS 开机或关机状态下均尝试升级
    • 页面显示“升级失败”，进度停留在 55%
    • 执行全擦写升级依旧失败
    • 签名问题和 UIDList 问题已解决
  • 关键日志错误：
    firmware_mgmt ERROR: control.lua(201): Upgrade Bios process failed, ret=-1

:receipt: 日志分析与根因定位

通过对提供的日志深入分析，可以梳理出完整的升级流程及失败节点：

:repeat_button: 升级流程回顾（基于 firmware_mgmt 日志）

  1. 任务创建成功

    • 创建升级任务 TaskID: 587718159
    • 开始解析 HPM 包，版本校验、签名验证均成功

  2. 准备阶段（Prepare）完成

    • MessageId 变为 FirmwareUpgradeComponent
    • 进入 PROCESS 阶段（Progress: 15 → 55）

  3. 关键失败点

    • Progress 达到 55 后长时间无进展
    • 最终报错：
      Upgrade Bios process failed, ret=-1
    • 状态变为 COMMON_FINISH → COMPLETED（失败完成）
    • 最终提示 FirmwareUpgradeError

:triangular_flag: 关键线索：Progress 停留在 55%，返回码 ret=-1

结合文档和知识库分析，该现象强烈指向以下两种可能性：

:warning: 可能原因分析

原因一：BIOS 资源树未正确加载（核心推断）

日志中多次出现 bmc.kepler.Systems.Bios 相关路径操作，但没有成功加载的确认信息。

:white_check_mark: 证据支持：

  • 知识库中明确提到：

    “Kltk Zhuyuanli explained that the BIOS upgrade failed because the /bmc/kepler/Systems/1/Bios was not loaded.”

  • 在您的日志中，虽然完成了包解析与签名验证，但未见与 bmc.kepler.Systems.Bios 成功交互的日志条目。
  • 此资源树通常由 BCU 模块加载，若环境为“天池模组环境”且无 BCU，则资源树不会自动加载。

:light_bulb: 行为逻辑：

当 bmc.kepler.Systems.Bios 服务未启动或资源树未加载时：

  • BIOS 升级流程在进入烧录（Flash）阶段时无法调用底层驱动
  • 导致升级任务超时或直接返回 ret=-1
  • 升级看似“进行中”，实则卡住无法推进

原因二：IPMB 通信总线被占用

:white_check_mark: 证据支持：

  • 知识库指出：

    “The BIOS upgrade process fails because IPMB Bus 0 is occupied, preventing message transmission.”

  • BIOS 升级过程中，BMC 需通过 IPMB-Bus 0 向主板发送命令（如切换 Flash 通道、触发重启等）
  • 若该总线繁忙（例如正在进行其他硬件操作），会导致升级失败

:light_bulb: 检查建议：

  • 检查是否有并发的 CPLD 升级、传感器读取高峰或其他 IPMI 操作
  • 在升级前确保系统处于空闲状态

原因三：SPI Flash 设备未就绪

:white_check_mark: 证据支持：

  • 知识库记录：

    “The BIOS upgrade failure is caused by the SPI flash device not being ready, as reported in the error log.”

  • 若底层 SPI Flash 驱动异常、保护锁未释放、芯片忙，则无法写入新固件

:light_bulb: 常见场景：

  • Flash 正在被其他进程访问
  • Flash 写保护使能
  • 更换 SPI 芯片后驱动不兼容

原因四：升级后版本未更新问题（二次验证）

即使升级“成功”，版本号未变可能是由于：

  • 固件写入成功，但 BMC 启动失败 → 触发分区回滚（见知识库 Q1）
  • 版本号由子固件组件管理，BMC 仅展示 → 升级完成后需手动触发版本读取

文档依据：

“升级非bmc固件的时候，有时候会升级失败……现象：升级之后版本号不变。原因：iBMC系统启动失败，三次未启动成功之后触发分区切换”

:white_check_mark: 解决方案与操作建议

:white_check_mark: 方案一：【紧急排查】检查 BIOS 资源树是否加载

  1. 登录 BMC CLI（通过 SSH 或串口）

  2. 执行以下命令检查服务状态：

    busctl --user list | grep bmc.kepler.Systems.Bios

    或：

    ps | grep bmc.kepler.Systems.Bios

  3. 如果无输出或状态异常：

    • 确认是否缺少 BCU 模块
    • 手动加载 BIOS 资源树服务（需联系开发提供正确启动脚本）

  4. 临时解决方法（适用于天池模组环境）：

    根据知识库提示：“解决方案是将 bcu 中涉及 bios 的资源树部分功能进行迁移，最好跟着产品走。”

:white_check_mark: 方案二：【规避干扰】在纯净环境下进行升级

  1. 重启 BMC 清理所有任务队列：

    reboot

  2. 重启后 立即进行 BIOS 升级，避免其他服务抢占总线

  3. 升级前确认无其他固件操作正在进行（如 CPLD、VRD）

:white_check_mark: 方案三：【绕过 Web UI】使用 CLI 命令行升级（推荐）

Web 界面可能存在资源管理缺陷，建议改用命令行控制升级流程。

示例命令（参考 OpenUBMC 实践）：

# 上传固件包至 /tmp
scp S920S10-KL4.41.102.260320.R.CMS_0791421.hpm root@bmc_ip:/tmp/

# 登录并执行升级（假设支持 ipmcset）
ipmcset -t fwupdate -d upgrade -v Bios -f /tmp/S920S10-KL4.41.102.260320.R.CMS_0791421.hpm

:warning: 具体命令需根据您的平台支持情况调整，请参考《QEMU 仿真与 BMC 业务开发指南》中的 ipmcget -d v 获取版本信息作为调试依据。

:white_check_mark: 方案四：【终极手段】使用 Redfish API 无感升级

OpenUBMC 支持通过 Redfish 实现无感升级，规避 Web UI 缺陷。

请求示例：

POST /redfish/v1/UpdateService/Actions/UpdateService.SimpleUpdate
Content-Type: application/json

{
  "ImageURI": "https://your-server/firmware/S920S10-KL4.41.102.260320.R.CMS_0791421.hpm",
  "Targets": [],
  "BiosActivatedScope": "AfterRestart"
}

:pushpin: 优势：可精确控制升级策略，绕开 Web 前端 bug

:white_check_mark: 方案五：【长期修复】确保系统依赖完整性

  • 确认 bmc.kepler.Systems.Bios 服务已打包并随系统启动自动加载
  • 在构建镜像时，确认以下组件存在：
    • bcu（Baseboard Control Unit）
    • bmc.kepler.Systems.Bios
    • bmc_upgrade Module
  • 如为定制化模组，需将 BIOS 升级所需资源树模块独立集成

:hammer_and_wrench: 附加建议

问题 建议
BMC 时间为 1970 年 系统时间未同步，可能影响日志追溯。建议配置 NTP：
ipmcset -t ntp -d enable -v true
日志中多次创建 cothread 可能是任务调度器频繁重试，说明升级流程存在阻塞
升级失败后版本未更新 检查是否发生分区自动回滚，可通过 ipmcget -d v 多次验证版本跳变

:books: 参考资料（来自上下文）

  • Kltk Zhuyuanli 的诊断经验：BIOS 升级失败常见于 /bmc/kepler/Systems/1/Bios 未加载
  • 固件升级机制：Web 页面升级依赖资源树加载，否则生成快照失败
  • OpenUBMC 25.09 特性：支持单 HPM 包多固件升级，BMC 升级异常时自恢复
  • Redfish 升级接口：支持 BiosActivatedScope 实现无感升级

:white_check_mark: 结论与建议

您遇到的 BIOS 升级失败最可能的原因是：

:red_exclamation_mark: bmc.kepler.Systems.Bios 服务未加载，导致无法执行底层 Flash 操作

:green_circle: 推荐操作步骤：

  1. 确认 BMC 是否具备 BIOS 管理能力（检查 BCU 是否缺失）
  2. 在 CLI 中手动验证 bmc.kepler.Systems.Bios 是否运行
  3. 尝试使用 Redfish API 或 CLI 命令行方式进行升级
  4. 升级后断电重启，确保新 BIOS 生效
  5. 联系产品团队确认是否需迁移 BCU 中的 BIOS 资源树功能

如以上方案仍无效，请收集以下信息进一步分析：

  • ipmcget -d v 输出的完整版本信息
  • ps | grep bios 输出
  • /var/log/app.log 中关于 bmc.kepler.Systems.Bios 的初始化日志

祝您升级顺利！

3

能发一份完整日志吗，后缀名改成txt应该可以传上来

4

上面又加入了BIOS模块的打印，目前看应该是falsh的权限没拿到BMC这边来，在找硬件一起看

5

好的，这边如果有问题我们再继续看。

6

spi_flash.lua:316: check device ready fail，很明显是硬件问题引起