BMC升级BIOS失败问题求助

交流互助区
1

BMC升级BIOS版本时，已经拿到控制权，报错查不到信息

  • 软件版本：OpenUBMC2509

开始有控制权的问题，硬件已经解决了，升级页面显示成功，其实没有写进去，怀疑是flash型号问题，目前已经换了推荐的flash型号MX25U12832FM2I02H，大小是128M，还是有这种错误，spi_flash.lua代码里找不到，请大神协助帮忙看看。

[升级过程日志如下]

2026-04-20 17:54:36.341503 web_backend NOTICE: init.lua(98): upload content length:number 4426698, remaining capacity space:number 128139264
2026-04-20 17:54:39.043444 bios NOTICE: signal.lua(180): Start the bios upgrade prepare phase
2026-04-20 17:54:39.044168 bios NOTICE: signal.lua(181): FirmwareIndex = "Firmware1" FirmwareMode = "Single" Platform = "" ComponentID = "2" TaskId = "2621954635"
2026-04-20 17:54:39.047267 general_hardware NOTICE: upgrade_subject.lua(82): [on_upgrade_prepare] firmware_type:Bios cur_firmware_type:Bios
2026-04-20 17:54:39.047719 general_hardware ERROR: upgrade_subject.lua(86): [on_upgrade_prepare] does not exists the observer, firmware_type:Bios
2026-04-20 17:54:39.060682 bios NOTICE: upgrade_service.lua(191): [bios]upgrade prepare: start
2026-04-20 17:54:39.061765 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from UPGRADE_READY to PREPARE_START
2026-04-20 17:54:39.062731 bios NOTICE: upgrade_service.lua(177): [bios]upgrade prepare: build package
2026-04-20 17:54:39.067603 bios NOTICE: package_cfg.lua(66): [bios]get package cfg Firmware1
2026-04-20 17:54:39.069495 bios NOTICE: package.lua(55): [bios]bios package is security type
2026-04-20 17:54:39.070328 bios NOTICE: upgrade_service.lua(185): [bios]upgrade prepare: pfr cache tmp hpm
2026-04-20 17:54:39.518797 bios NOTICE: gold_package.lua(115): [bios]gold package: backup tmp path success, system id is 1
2026-04-20 17:54:39.519307 bios NOTICE: upgrade_service.lua(187): [bios]upgrade prepare: reply messgae
2026-04-20 17:54:39.520531 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_START to PREPARE_FINISH
2026-04-20 17:54:39.521529 bios NOTICE: signal.lua(155): [bios] prepare set system 1 verion KL4.41.101.260327.R
2026-04-20 17:54:39.613581 firmware_mgmt NOTICE: [worker](9): start action in worker
2026-04-20 17:54:39.688911 firmware_mgmt NOTICE: [worker](14): execute before action script successfully
2026-04-20 17:54:40.823793 general_hardware ERROR: upgrade_subject.lua(105): [on_upgrade_process] does not exists the observer, firmware_type:Bios
2026-04-20 17:54:40.831661 bios NOTICE: signal.lua(257): Start the bios upgrade process phase
2026-04-20 17:54:40.842784 bios NOTICE: firmware_multihost.lua(232): [bios] get is_online_force nil, system id: 1
2026-04-20 17:54:40.852859 bios NOTICE: firmware_multihost.lua(216): [bios] get activate mode nil, system id: 1
2026-04-20 17:54:40.977504 bios NOTICE: upgrade_service.lua(548): [bios]upgrade process: start
2026-04-20 17:54:40.978869 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_FINISH to PROCESS_START
2026-04-20 17:54:40.980261 bios NOTICE: upgrade_service.lua(458): [bios] singlehost upgrade process
2026-04-20 17:54:40.981132 bios NOTICE: upgrade_service.lua(365): [bios]upgrade process: system 1, upgrade mode(Cold), period(Period2), package type(Normal)
2026-04-20 17:54:40.985128 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add PackageCheck executor successfully
2026-04-20 17:54:40.985648 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Backup executor successfully
2026-04-20 17:54:40.985983 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Cache executor successfully
2026-04-20 17:54:40.986717 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add LockPower executor successfully
2026-04-20 17:54:40.987357 bios NOTICE: upgrade_executor.lua(177): load chipv1 spikodrv
2026-04-20 17:54:40.988191 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SpiDriver executor successfully
2026-04-20 17:54:40.988733 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add DecompressFile executor successfully
2026-04-20 17:54:40.989205 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add ParserBin executor successfully
2026-04-20 17:54:40.989794 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SelectChannel executor successfully
2026-04-20 17:54:40.990205 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add UpgradeComponent executor successfully
2026-04-20 17:54:40.992102 bios NOTICE: upgrade_executor.lua(144): [bios]upgrade chain: package_check (executor) start
2026-04-20 17:54:40.998848 bios NOTICE: upgrade_executor.lua(84): [bios]upgrade chain: back (executor) start
2026-04-20 17:54:41.319531 bios NOTICE: upgrade_executor.lua(124): [bios]upgrade chain: cache (executor) start
2026-04-20 17:54:41.326741 bios NOTICE: upgrade_executor.lua(158): [bios]upgrade chain: power_lock (executor) lock
2026-04-20 17:54:41.336424 fructrl NOTICE: pwr_on_lock.lua(48): [System:nil][Upgrade] add item to lock_table successfully.
2026-04-20 17:54:41.335720 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=true, timeout=1000, appname=Upgrade, reason=bios
2026-04-20 17:54:41.342380 bios NOTICE: power_lock.lua(102): [bios]power_lock: lock success.
2026-04-20 17:54:41.344085 bios NOTICE: upgrade_executor.lua(221): [bios]upgrade chain: spi_driver (executor) start
2026-04-20 17:54:41.350591 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-20 17:54:41.667269 bios NOTICE: spi_flash.lua(308): [spi]check_device_ready: device /dev/mtd0 ready
2026-04-20 17:54:41.676859 bios NOTICE: upgrade_executor.lua(246): [bios]upgrade chain: decompress_file (executor) start
2026-04-20 17:54:47.749481 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-20 17:54:47.750528 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-20 17:54:48.518966 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-20 17:54:48.519277 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-20 17:54:48.522215 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-20 17:54:48.527063 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-20 17:54:52.563125 bios NOTICE: upgrade_executor.lua(267): [bios]upgrade chain: parse_bin (executor) start
2026-04-20 17:54:54.305000 bios NOTICE: bin_parser_period2.lua(123): 1 = {   updateSize = 5570560   updateAddr = 8388608 } 2 = {   updateSize = 393216   updateAddr = 14024704 } 3 = {   updateSize = 2359296   updateAddr = 14417920 }
2026-04-20 17:54:54.305319 bios NOTICE: bin_parser_period2.lua(156): unpack bios upgrade file successfully
2026-04-20 17:54:54.306475 bios NOTICE: upgrade_executor.lua(288): [bios]upgrade chain: select_channel (executor) start
2026-04-20 17:54:54.307032 bios NOTICE: upgrade_executor.lua(320): [bios]upgrade chain: upgrade_component (executor) start
2026-04-20 17:54:54.857824 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-20 17:54:54.858998 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:54.859394 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 1, total block: 88
2026-04-20 17:54:54.889063 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-20 17:54:54.889552 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:54.890038 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 1, total block: 88
2026-04-20 17:54:54.909018 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-20 17:54:54.909384 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:54.909990 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 1, total block: 88
2026-04-20 17:54:54.972654 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-20 17:54:54.974906 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:54.976421 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 2, total block: 88
2026-04-20 17:54:55.003163 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-20 17:54:55.004897 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.006310 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 2, total block: 88
2026-04-20 17:54:55.032946 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-20 17:54:55.033951 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.034525 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 2, total block: 88
2026-04-20 17:54:55.095763 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-20 17:54:55.097592 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.100205 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 3, total block: 88
2026-04-20 17:54:55.133819 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-20 17:54:55.134974 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.136741 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 3, total block: 88
2026-04-20 17:54:55.160328 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-20 17:54:55.162311 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.163755 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 3, total block: 88
2026-04-20 17:54:55.220134 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-20 17:54:55.222875 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.225152 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 4, total block: 88
2026-04-20 17:54:55.251195 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-20 17:54:55.252448 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.253834 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 4, total block: 88
2026-04-20 17:54:55.282342 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-20 17:54:55.283830 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.287653 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 4, total block: 88
2026-04-20 17:54:55.355452 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-20 17:54:55.356950 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.358187 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 5, total block: 88
2026-04-20 17:54:55.384831 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-20 17:54:55.387970 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.389062 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 5, total block: 88
2026-04-20 17:54:55.415413 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-20 17:54:55.416500 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.417996 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 5, total block: 88
2026-04-20 17:54:55.486061 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 327680 - 337920
2026-04-20 17:54:55.487921 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:55.490096 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 6, total block: 88
2026-04-20 17:54:55.520912 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 6, total block: 88
2026-04-20 17:54:55.552539 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 6, total block: 88
2026-04-20 17:54:55.610038 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 393216 - 403456
2026-04-20 17:54:55.612983 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 7, total block: 88
2026-04-20 17:54:55.652404 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 7, total block: 88
2026-04-20 17:54:55.690500 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 7, total block: 88
2026-04-20 17:54:55.754756 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 458752 - 468992
2026-04-20 17:54:55.755669 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 8, total block: 88
2026-04-20 17:54:55.784044 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 8, total block: 88
2026-04-20 17:54:55.804719 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 8, total block: 88
2026-04-20 17:54:55.875131 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 524288 - 534528
2026-04-20 17:54:55.876558 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 9, total block: 88
2026-04-20 17:54:55.907292 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 9, total block: 88
2026-04-20 17:54:55.941285 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 9, total block: 88
2026-04-20 17:54:56.000265 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 589824 - 600064
2026-04-20 17:54:56.001736 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 10, total block: 88
2026-04-20 17:54:56.031498 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 10, total block: 88
2026-04-20 17:54:56.054100 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 10, total block: 88
2026-04-20 17:54:56.113510 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 655360 - 665600
2026-04-20 17:54:56.114222 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 11, total block: 88
2026-04-20 17:54:56.228305 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 720896 - 731136
2026-04-20 17:54:56.366223 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 786432 - 796672
2026-04-20 17:54:56.489658 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 851968 - 862208
2026-04-20 17:54:56.620883 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 917504 - 927744
2026-04-20 17:54:56.755501 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 983040 - 993280
2026-04-20 17:54:56.874284 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1048576 - 1058816
2026-04-20 17:54:56.995344 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1114112 - 1124352
2026-04-20 17:54:57.097319 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1179648 - 1189888
2026-04-20 17:54:57.198337 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1245184 - 1255424
2026-04-20 17:54:57.304663 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1310720 - 1320960
2026-04-20 17:55:05.088785 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-20 17:55:05.089095 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-20 17:55:05.741545 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 1 to flash successfully
2026-04-20 17:55:16.455652 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 2 to flash successfully
2026-04-20 17:55:17.706034 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 3 to flash successfully
2026-04-20 17:55:22.576435 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 4 to flash successfully
2026-04-20 17:55:22.582187 bios NOTICE: upgrade_executor.lua(335): [bios]upgrade chain: upgrade_component (executor) finish
2026-04-20 17:55:22.610102 bios NOTICE: upgrade_executor.lua(254): [bios]upgrade chain: decompress_file (executor) end
2026-04-20 17:55:22.617116 bios NOTICE: bios_object_mutihost.lua(123): [bios]start fetch component version info, system is 1
2026-04-20 17:55:23.055663 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-20 17:55:23.056552 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-20 17:55:23.076566 bios NOTICE: upgrade_executor.lua(230): [bios]upgrade chain: spi_driver (executor) end
2026-04-20 17:55:23.085031 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=false, timeout=1000, appname=Upgrade, reason=bios
2026-04-20 17:55:23.085736 fructrl NOTICE: pwr_on_lock.lua(71): [System:nil]Update item successfully, appname=(Upgrade), reason=(bios), pwronlocked=(false), timeout=(1000)
2026-04-20 17:55:23.087731 bios NOTICE: upgrade_executor.lua(167): [bios]upgrade chain: power_lock (executor) unlock
2026-04-20 17:55:23.088738 bios NOTICE: pfr_service.lua(317): [bios]pfr: system 1 no need wait bios effective
2026-04-20 17:55:23.090443 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PROCESS_START to PROCESS_FINISH
2026-04-20 17:55:23.106322 bios NOTICE: firmware_multihost.lua(225): [bios] clear activate mode(table: 0x7d135d509ee0), system id: 1
2026-04-20 17:55:23.205899 firmware_mgmt NOTICE: [worker](9): start action in worker
2026-04-20 17:55:23.278760 firmware_mgmt NOTICE: [worker](14): execute finish action script successfully
2026-04-20 17:55:23.350034 fructrl NOTICE: pwr_on_lock.lua(143): [System:nil]Delete pwr_on_lock item, appname=(Upgrade), reason=(bios)
2026-04-20 17:55:23.351665 fructrl NOTICE: pwr_on_lock.lua(149): [System:nil]PwrOnLocked has been unlocked
2026-04-20 17:55:24.315358 bios NOTICE: signal.lua(293): Start the bios upgrade finish phase
2026-04-20 17:55:24.316914 bios NOTICE: upgrade_service.lua(593): [bios]upgrade finish: start
2026-04-20 17:55:24.319943 general_hardware ERROR: upgrade_subject.lua(124): [on_upgrade_finish] does not exists the observer, firmware_type:Bios
2026-04-20 17:55:24.317288 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PROCESS_FINISH to FIRMWARE_FINISHING
2026-04-20 17:55:24.317624 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from FIRMWARE_FINISHING to UPGRADE_READY
2026-04-20 17:55:24.317958 bios NOTICE: upgrade_service.lua(93): [bios]mode recover to Cold
2026-04-20 17:55:24.318289 bios NOTICE: upgrade_service.lua(597): [bios]hpm upgrade: bios package upgrade successfully
2026-04-20 17:55:24.339422 bios ERROR: upgrade_service.lua(140): [TPCM]refresh bios digest after upgrade bios failed!
2026-04-20 17:55:24.341494 bios NOTICE: upgrade_service.lua(575): [bios]FirmwareEffectiveStatus change to Effecting, system id : 1
2026-04-20 17:55:24.341828 bios NOTICE: pfr_service.lua(95): [PfrService]PfrService: try unlock fructl forever lock.
2026-04-20 17:55:24.467070 bios NOTICE: upgrade_service.lua(932): [BIOS]Start judge power status
2026-04-20 17:55:24.849303 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=false, timeout=65535, appname=Upgrade, reason=VerifyFlash
2026-04-20 17:55:24.852089 bios NOTICE: pfr_service.lua(107): [PfrService]PfrService: unlock fructl forever lock success.
2

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

:white_check_mark: 总结

:red_exclamation_mark: 本次BIOS升级失败的根本原因不是控制权问题，而是写入SPI Flash后数据校验失败，表明硬件SPI链路或Flash芯片存在可靠性缺陷。

请优先排查物理连接与信号完整性，并尝试更换为已验证的 MX25U25645G 芯片进行测试。只有在确保底层Flash可稳定读写的基础上，上层升级流程才可能成功。

如果您能提供 dmesg 或 framework.log 的底层驱动日志，可进一步分析驱动层交互细节。

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

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

根据您提供的日志信息和问题描述，本次BMC升级BIOS虽然页面显示成功，但实际未生效的问题核心在于SPI Flash写入过程中的数据校验失败，而非控制权或连接问题。

:magnifying_glass_tilted_left: 问题定位分析

1. 关键错误日志分析

从您的升级日志中可以发现以下关键错误信息：

2026-04-20 17:54:54.857824 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-20 17:54:54.858998 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-20 17:54:54.859394 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1 cur_block: 1, total block: 88
...

含义解析：

  • 写入Flash后，驱动程序进行了数据读回比对（verify）。
  • 比对发现从地址 0x0 开始的前10240字节内容与原始升级包数据不一致。
  • 尽管系统重试多次，仍然失败。
  • 错误发生在 spi_flash.lua 文件中，负责SPI Flash读写操作。

尽管后续日志显示：

[component upgrade]: write region X to flash successfully
[bios]hpm upgrade: bios package upgrade successfully

但这只是流程上的状态标记成功，并不代表数据真正正确写入并持久化。

2. 问题本质判断

判断项 结论
是否获得SPI总线控制权 :white_check_mark: 是（check_device_ready: device /dev/mtd0 ready 表明已切换）
驱动是否加载 :white_check_mark: 是（load chipv1 spikodrv 显示驱动已加载）
Flash型号是否匹配？ :warning: 可能相关，但非根本原因（MX25U12832FM2I02H是常用型号）
数据是否成功写入Flash？ :cross_mark: 失败（数据验证失败是铁证）

:pushpin: 结论： 本次升级失败的根本原因是——数据写入SPI Flash后未能通过校验，即写入操作物理执行了，但数据完整性出错。

:puzzle_piece: 根本原因推测（基于已有上下文）

结合知识库信息和日志行为，可能原因如下：

:white_check_mark: 【主因】硬件SPI链路信号完整性问题

  • 尽管控制权已拿到，且设备 /dev/mtd0 可用，不等于信号传输稳定可靠。
  • 日志显示写入后验证失败，这是典型的SPI通信过程中数据错位或干扰现象。
  • 相关支持证据：
    • 在已有案例（doc_id:5）中，用户因SPI链路接错SFC1而非SFC0导致升级失败，后通过修正硬件连接解决。
    • 知识库明确指出：BIOS Upgrade Failure 与 Hardware SPI Link 直接相关。
    • 您提到“开始有控制权的问题，硬件已经解决了”——建议重新审视是否彻底解决，包括：
      • 所有SPI信号线（CLK, MOSI, MISO, CS, WP, HOLD）连接正确？
      • 是否存在虚焊、串扰、阻抗不匹配？
      • 是否使用了电平转换器？其带宽是否足够（例如25MHz时钟需大于50MHz支持）？

:warning: 【次因】Flash芯片兼容性或编程电压问题

  • 虽然更换为推荐型号，但仍需确认：
    • BMC的SPI控制器是否完全支持该Flash芯片的指令集、时序参数、电压范围？
    • 某些Flash在低电压（如1.8V）下写入不稳定，而BMC输出为3.3V需匹配电平转换。
  • 知识库提及： MX25U25645G 是常见型号且被系统日志正确识别，若当前使用的 MX25U12832FM2I02H 未充分验证，可能存在兼容性风险。

:warning: 【潜在原因】固件打包或解包阶段数据损坏

  • 日志显示：
    unpack bios upgrade file successfully
    说明解压正常，但不能排除：
    • 升级包本身在构建时未针对目标Flash做正确偏移/分割。
    • 解包后的BIN文件在写入前发生内存污染。
  • 特别注意 Period2 模式升级对多个region分段写入的逻辑复杂度较高。

:white_check_mark: 解决建议与排查步骤

:white_check_mark: 步骤1：彻底检查硬件SPI连接

原则：能通信 ≠ 能稳定通信

  1. 确认SPI通道正确：

    • 查看原理图，确保BMC连接的是 SFC0 而非 SFC1。
    • 确认 CSN 选择正确。

  2. 信号完整性检查：

    • 使用示波器检查 SPI_CLK、MOSI 波形是否有畸变、振铃或延时。
    • 确保 HOLD# 和 WP# 引脚处于无效状态（通常上拉）。
    • 若使用电平转换器，确认其支持 25MHz及以上速率（推荐74LVC系列）。

  3. 更换Flash芯片测试：

    • 尝试使用知识库中已验证的型号 MX25U25645G 进行替换测试。
    • 该芯片在多份日志中被成功识别和操作，具有更高兼容性保障。

:white_check_mark: 步骤2：手动验证Flash读写能力

目的：排除软件流程干扰，直接测试底层读写。

  1. 在BMC系统中尝试执行以下命令（如权限允许）：

    # 擦除Flash（谨慎操作）
flash_erase /dev/mtd0 0 0
# 向Flash写入测试数据
echo "TEST_DATA" > /tmp/test.bin
nandwrite /dev/mtd0 /tmp/test.bin
# 读出并比对
nanddump -l 32 /dev/mtd0

    如果读出数据与写入不符，则确凿证明硬件链路或Flash本身存在问题。

  2. 检查设备是否存在：

    ls /dev/mtd*
cat /proc/mtd

    若无 /dev/mtd0，则驱动未正确定义Flash分区。

:white_check_mark: 步骤3：查看完整系统日志与配置

  1. 检查CSR配置中Flash通道定义：

    参考知识库内容：

    • FlashChannel 和 FlashChannelIds 必须正确指向目标Flash。
    • 配置示例（伪代码）：
    {
  "FlashChannel": "sfc0",
  "FlashChannelIds": ["sfc0_csn0"]
}

  2. 确认BIOS资源树是否加载：

    • 若 /bmc/kepler/Systems/1/Bios 未加载，会导致快照生成失败（见知识库Kltk Zhuyuanli所述）。
    • 检查系统启动日志是否有 load bios resource tree 成功记录。

:white_check_mark: 步骤4：软件层面增强日志与调试

  1. 增加spi_flash.lua日志深度：

    • 修改 spi_flash.lua，在 write_data_to_flash 前后增加数据dump：
      log("INFO", "Writing data chunk at addr 0x" .. addr .. ": " .. to_hex(data:sub(1,16)))
    • 捕获写入前的数据与Flash读回数据做比对。

  2. 启用低级驱动调试：

    • 查看 dmesg | grep sfc 或 hisfc_drv_probe 输出，确认底层驱动无错误。

:white_check_mark: 步骤5：尝试强制刷新+回退机制验证

  1. 触发一次完整擦除再升级：

    • 在升级前手动全擦Flash（风险操作，请备份）。
    • 排除非空Flash导致的写入异常。

  2. 确认回滚机制是否触发：

    • 若升级失败未自动回滚，说明系统误判为“成功”。
    • 检查 FirmwareInfo 中版本是否真实更新：
      GetFirmwareInfo("Bios")

:toolbox: 推荐解决方案顺序

优先级 操作 原因
:red_circle: 高 用示波器检查SPI CLK/MOSI波形质量 定位物理层问题最有效
:red_circle: 高 替换为 MX25U25645G Flash芯片测试 已知良好型号，排除兼容性
:yellow_circle: 中 手动执行 flash_erase + nandwrite 测试 验证底层读写能力
:yellow_circle: 中 检查CSR中 FlashChannel 配置 防止逻辑通道错位
:green_circle: 低 增加 spi_flash.lua 调试日志 便于长期诊断

:books: 相关参考知识

  • :white_check_mark: spi_flash.lua 是SPI Flash操作的核心脚本，负责设备就绪检查、擦除、写入与校验。
  • :white_check_mark: MX25U25645G 是系统中已被成功识别和操作的Flash型号。
  • :white_check_mark: 硬件SPI链路松动或接错是同类问题的常见根源（见doc_id:5）。
  • :white_check_mark: 即使升级流程标记“成功”，数据校验失败也意味着实质失败。

:white_check_mark: 总结

:red_exclamation_mark: 本次BIOS升级失败的根本原因不是控制权问题，而是写入SPI Flash后数据校验失败，表明硬件SPI链路或Flash芯片存在可靠性缺陷。

请优先排查物理连接与信号完整性，并尝试更换为已验证的 MX25U25645G 芯片进行测试。只有在确保底层Flash可稳定读写的基础上，上层升级流程才可能成功。

如果您能提供 dmesg 或 framework.log 的底层驱动日志，可进一步分析驱动层交互细节。

3

附上相关的日志：
app.log

~ #
~ # tail -f /var/log/app.log
2026-04-21 10:52:59.661094 power_mgmt ERROR: psu.lua(435): Update power[01013B] level failed
2026-04-21 10:53:05.559175 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:05.560348 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:08.983264 complex_sensor NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:24, duration:5 min, sent signals:65, received signals:38, sent rpcs:189, received rpcs:19
2026-04-21 10:53:10.053055 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:53:10.053373 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:53:10.056352 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:53:10.062516 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:53:10.818917 fault_diagnosis NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:26, duration:5 min, sent signals:205, received signals:14, sent rpcs:102, received rpcs:5
2026-04-21 10:53:14.656968 event NOTICE: event_management.lua(1095): second resume software event finished
2026-04-21 10:53:23.593640 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=0, eth_name=eth0
2026-04-21 10:53:24.342418 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:53:24.342707 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 0, eth_name = eth0
2026-04-21 10:53:25.086666 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:53:25.087809 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=1, eth_name=eth0
2026-04-21 10:53:25.836898 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:53:25.837878 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 1, eth_name = eth0
2026-04-21 10:53:26.595600 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:53:26.597269 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:53:26.597595 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:53:27.363673 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:53:27.364082 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:53:27.366996 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:53:27.369517 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:53:37.402493 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:37.403672 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:37.410624 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:37.411730 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:53:37.412557 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:37.413892 firmware_mgmt INFO: debug.lua(548): firmware_mgmt attached debug console 5582
2026-04-21 10:53:37.415681 firmware_mgmt INFO: debug.lua(552): firmware_mgmt set debug client context
2026-04-21 10:53:37.416995 firmware_mgmt INFO: debug.lua(555): firmware_mgmt started heartbeat check of debug console 5582
2026-04-21 10:53:37.419491 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34a8bab6a0] exit
2026-04-21 10:53:37.432299 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:53:37.433335 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:37.434225 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34a8bab6a0] exit
2026-04-21 10:53:37.441415 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:39.024358 capability_proxy NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:14, received signals:0, sent rpcs:2, received rpcs:45
2026-04-21 10:53:39.054602 certificate NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:102, received signals:0, sent rpcs:12, received rpcs:39
2026-04-21 10:53:39.378269 bmc_time NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:52, received signals:14, sent rpcs:56, received rpcs:39
2026-04-21 10:53:39.560637 bmc_upgrade NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:28, received signals:14, sent rpcs:18, received rpcs:14
2026-04-21 10:53:39.621182 bmc_health NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:12, received signals:2, sent rpcs:13, received rpcs:5
2026-04-21 10:53:39.752842 fructrl NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:67, received signals:16, sent rpcs:74, received rpcs:35
2026-04-21 10:53:39.957131 ipmi_core NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:83, received signals:1587, sent rpcs:761, received rpcs:80
2026-04-21 10:53:39.977304 firmware_mgmt NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:55, duration:5 min, sent signals:98, received signals:16, sent rpcs:30, received rpcs:39
2026-04-21 10:53:40.052105 trust NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:56, duration:5 min, sent signals:72, received signals:14, sent rpcs:13, received rpcs:29
2026-04-21 10:53:40.099192 bmc_soc NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:56, duration:5 min, sent signals:72, received signals:20, sent rpcs:60, received rpcs:19
2026-04-21 10:53:40.519160 iam NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:56, duration:5 min, sent signals:111, received signals:157, sent rpcs:63, received rpcs:262
2026-04-21 10:53:40.676247 bmc_network NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:56, duration:5 min, sent signals:300, received signals:15, sent rpcs:36, received rpcs:170
2026-04-21 10:53:40.926642 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=0, eth_name=eth0
2026-04-21 10:53:41.095797 host_agent NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:57, duration:5 min, sent signals:46, received signals:16, sent rpcs:6, received rpcs:23
2026-04-21 10:53:41.390820 frudata NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:57, duration:5 min, sent signals:267, received signals:97, sent rpcs:55, received rpcs:136
2026-04-21 10:53:41.671913 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:53:41.672286 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 0, eth_name = eth0
2026-04-21 10:53:42.195279 sensor NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:00:58, duration:5 min, sent signals:1002, received signals:276, sent rpcs:55, received rpcs:116
2026-04-21 10:53:42.417491 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b21586d8]
2026-04-21 10:53:42.418625 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:42.419431 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b21586d8] exit
2026-04-21 10:53:42.422299 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b21586d8]
2026-04-21 10:53:42.423322 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:42.424410 firmware_mgmt DEBUG: app_preloader.lua(206): ./opt/bmc/libmc/lualib/mc/mdb/micro_component/debug.lua:500: app(firmware_mgmt/service/main) fork func, count=1, delay=0
2026-04-21 10:53:42.428301 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:53:42.429542 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=1, eth_name=eth0
2026-04-21 10:53:43.179538 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:53:43.179833 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 1, eth_name = eth0
2026-04-21 10:53:43.939374 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:53:43.941385 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:53:43.941745 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:53:44.008925 pcie_device NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:01:00, duration:5 min, sent signals:39, received signals:16, sent rpcs:15, received rpcs:27
2026-04-21 10:53:44.212714 compute NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:01:00, duration:5 min, sent signals:330, received signals:86, sent rpcs:170, received rpcs:367
2026-04-21 10:53:45.488037 bios NOTICE: start_profiling.lua(151): profiling finished, start time:1970-01-01 00:01:01, duration:5 min, sent signals:138, received signals:18, sent rpcs:15, received rpcs:59
2026-04-21 10:53:46.127503 certificate NOTICE: certificate_service.lua(577): clean old cert nearly expired alarm done
2026-04-21 10:53:47.601155 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:47.602558 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:53:47.603612 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:53:47.607281 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[:1.153], path[/bmc/kepler/firmware_mgmt/MicroComponent], interface[bmc.kepler.MicroComponent.Debug], name[DlogType], value["file"]->["local"], 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/libmc/lualib/mc/logging.lua:459: in function 'log_easy'  ./opt/bmc/libmc/lualib/mc/logging.lua:463: in function 'debug_easy'  ./opt/bmc/libmc/lualib/traceback/object.lua:83: in function 'before_set_value'  ./opt/bmc/libmc/lualib/traceback/object.lua:88: in function 'set_value'  ./opt/bmc/libmc/lualib/sd_bus/object.lua:415: in function <./opt/bmc/libmc/lualib/sd_bus/object.lua:407>  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/sd_bus/object.lua:421: in function 'set_value'  ...  ./opt/bmc/libmc/lualib/dbus/tree.lua:198: in function <./opt/bmc/libmc/lualib/dbus/tree.lua:180>  [C]: in function 'xpcall'  ./opt/bmc/libmc/lualib/mc/error/common.lua:46: in function 'safe_call'  ./opt/bmc/libmc/lualib/dbus/bus_base.lua:282: in function ''  /opt/bmc/skynet/lualib/skynet.lua: in function </opt/bmc/skynet/lualib/skynet.lua:0>  [builtin#21]: at 0xffff9933d3c0  [C]: in function 'pcall'  ./opt/bmc/libmc/lualib/mc/context.lua:205: in function 'with_context'  ./opt/bmc/libmc/lualib/mc/app_preloader.lua:92: in function ''  /opt/bmc/skynet/lualib/skynet.lua: in function </opt/bmc/skynet/lualib/skynet.lua:0>]
2026-04-21 10:53:51.353394 ums NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:51, duration:5 min, sent signals:53, received signals:16, sent rpcs:12, received rpcs:16
2026-04-21 10:53:51.373812 nsm NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:51, duration:5 min, sent signals:167, received signals:74, sent rpcs:99, received rpcs:36
2026-04-21 10:53:51.799043 observability NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:51, duration:5 min, sent signals:18, received signals:1, sent rpcs:12, received rpcs:3
2026-04-21 10:53:52.041752 oms NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:52, duration:5 min, sent signals:57, received signals:15, sent rpcs:66, received rpcs:8
2026-04-21 10:53:52.670330 event NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:52, duration:5 min, sent signals:26, received signals:59, sent rpcs:82, received rpcs:69
2026-04-21 10:53:52.790215 power_mgmt NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:52, duration:5 min, sent signals:115, received signals:20, sent rpcs:2763, received rpcs:21
2026-04-21 10:53:52.851583 thermal_mgmt NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:52, duration:5 min, sent signals:348, received signals:699, sent rpcs:495, received rpcs:108
2026-04-21 10:53:55.533315 lsw NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:55, duration:5 min, sent signals:16, received signals:14, sent rpcs:5, received rpcs:5
2026-04-21 10:53:59.007958 mctpd NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:59, duration:5 min, sent signals:24, received signals:16, sent rpcs:4, received rpcs:3
2026-04-21 10:53:59.058724 chassis NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:59, duration:5 min, sent signals:54, received signals:106, sent rpcs:8, received rpcs:71
2026-04-21 10:53:59.510949 manufacture NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:48:59, duration:5 min, sent signals:20, received signals:14, sent rpcs:11, received rpcs:9
2026-04-21 10:54:00.270448 network_adapter NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:00, duration:5 min, sent signals:39, received signals:18, sent rpcs:32, received rpcs:14
2026-04-21 10:54:00.972949 ai_engine NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:00, duration:5 min, sent signals:10, received signals:0, sent rpcs:2, received rpcs:4
2026-04-21 10:54:01.396379 web_backend NOTICE: init.lua(98): upload content length:number 4426698, remaining capacity space:number 129462272
2026-04-21 10:54:01.523803 general_hardware NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:01, duration:5 min, sent signals:235, received signals:59, sent rpcs:1003, received rpcs:58
2026-04-21 10:54:01.586552 storage NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:01, duration:5 min, sent signals:123, received signals:19, sent rpcs:10, received rpcs:55
2026-04-21 10:54:02.881045 metric_analyzer NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:02, duration:5 min, sent signals:23, received signals:639, sent rpcs:477, received rpcs:7
2026-04-21 10:54:03.124318 fault_diagnosis NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:03, duration:5 min, sent signals:207, received signals:16, sent rpcs:556, received rpcs:226
2026-04-21 10:54:04.200135 general_hardware NOTICE: upgrade_subject.lua(82): [on_upgrade_prepare] firmware_type:Bios cur_firmware_type:Bios
2026-04-21 10:54:04.200480 general_hardware ERROR: upgrade_subject.lua(86): [on_upgrade_prepare] does not exists the observer, firmware_type:Bios
2026-04-21 10:54:04.201770 ddns NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:04, duration:5 min, sent signals:24, received signals:0, sent rpcs:4, received rpcs:4
2026-04-21 10:54:04.202124 bios NOTICE: signal.lua(180): Start the bios upgrade prepare phase
2026-04-21 10:54:04.202897 bios NOTICE: signal.lua(181): ComponentID = "2" TaskId = "2866844768" FirmwareMode = "Single" Platform = "" FirmwareIndex = "Firmware1"
2026-04-21 10:54:04.222021 bios NOTICE: upgrade_service.lua(191): [bios]upgrade prepare: start
2026-04-21 10:54:04.222504 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from UPGRADE_READY to PREPARE_START
2026-04-21 10:54:04.222945 bios NOTICE: upgrade_service.lua(177): [bios]upgrade prepare: build package
2026-04-21 10:54:04.225917 bios NOTICE: package_cfg.lua(66): [bios]get package cfg Firmware1
2026-04-21 10:54:04.228624 bios NOTICE: package.lua(55): [bios]bios package is security type
2026-04-21 10:54:04.229900 bios NOTICE: upgrade_service.lua(185): [bios]upgrade prepare: pfr cache tmp hpm
2026-04-21 10:54:04.651211 bios NOTICE: gold_package.lua(115): [bios]gold package: backup tmp path success, system id is 1
2026-04-21 10:54:04.651594 bios NOTICE: upgrade_service.lua(187): [bios]upgrade prepare: reply messgae
2026-04-21 10:54:04.652096 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_START to PREPARE_FINISH
2026-04-21 10:54:04.653061 bios NOTICE: signal.lua(155): [bios] prepare set system 1 verion KL4.41.101.260327.R
2026-04-21 10:54:04.734693 firmware_mgmt NOTICE: [worker](9): start action in worker
2026-04-21 10:54:04.812287 firmware_mgmt NOTICE: [worker](14): execute before action script successfully
2026-04-21 10:54:05.946246 general_hardware ERROR: upgrade_subject.lua(105): [on_upgrade_process] does not exists the observer, firmware_type:Bios
2026-04-21 10:54:05.960720 bios NOTICE: signal.lua(257): Start the bios upgrade process phase
2026-04-21 10:54:05.972582 bios NOTICE: firmware_multihost.lua(232): [bios] get is_online_force nil, system id: 1
2026-04-21 10:54:05.981773 bios NOTICE: firmware_multihost.lua(216): [bios] get activate mode nil, system id: 1
2026-04-21 10:54:06.098838 bios NOTICE: upgrade_service.lua(548): [bios]upgrade process: start
2026-04-21 10:54:06.100273 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PREPARE_FINISH to PROCESS_START
2026-04-21 10:54:06.101082 bios NOTICE: upgrade_service.lua(458): [bios] singlehost upgrade process
2026-04-21 10:54:06.101660 bios NOTICE: upgrade_service.lua(365): [bios]upgrade process: system 1, upgrade mode(Cold), period(Period2), package type(Normal)
2026-04-21 10:54:06.103354 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add PackageCheck executor successfully
2026-04-21 10:54:06.104044 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Backup executor successfully
2026-04-21 10:54:06.104395 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add Cache executor successfully
2026-04-21 10:54:06.105030 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add LockPower executor successfully
2026-04-21 10:54:06.105793 bios NOTICE: upgrade_executor.lua(177): load chipv1 spikodrv
2026-04-21 10:54:06.108230 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SpiDriver executor successfully
2026-04-21 10:54:06.109861 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add DecompressFile executor successfully
2026-04-21 10:54:06.110480 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add ParserBin executor successfully
2026-04-21 10:54:06.112908 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add SelectChannel executor successfully
2026-04-21 10:54:06.114240 bios NOTICE: upgrade_scenarios.lua(52): [bios]UpgradeScenarios: process chain add UpgradeComponent executor successfully
2026-04-21 10:54:06.118221 bios NOTICE: upgrade_executor.lua(144): [bios]upgrade chain: package_check (executor) start
2026-04-21 10:54:06.125469 bios NOTICE: upgrade_executor.lua(84): [bios]upgrade chain: back (executor) start
2026-04-21 10:54:06.492164 bios NOTICE: upgrade_executor.lua(124): [bios]upgrade chain: cache (executor) start
2026-04-21 10:54:06.497678 bios NOTICE: upgrade_executor.lua(158): [bios]upgrade chain: power_lock (executor) lock
2026-04-21 10:54:06.507388 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=true, timeout=1000, appname=Upgrade, reason=bios
2026-04-21 10:54:06.509524 fructrl NOTICE: pwr_on_lock.lua(48): [System:nil][Upgrade] add item to lock_table successfully.
2026-04-21 10:54:06.516329 bios NOTICE: power_lock.lua(102): [bios]power_lock: lock success.
2026-04-21 10:54:06.516766 bios NOTICE: upgrade_executor.lua(221): [bios]upgrade chain: spi_driver (executor) start
2026-04-21 10:54:06.523009 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-21 10:54:06.927916 bios NOTICE: spi_flash.lua(308): [spi]check_device_ready: device /dev/mtd0 ready
2026-04-21 10:54:06.948760 bios NOTICE: upgrade_executor.lua(246): [bios]upgrade chain: decompress_file (executor) start
2026-04-21 10:54:07.964695 remote_console NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:07, duration:5 min, sent signals:25, received signals:14, sent rpcs:8, received rpcs:4
2026-04-21 10:54:08.067182 cooling NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:08, duration:5 min, sent signals:32, received signals:90, sent rpcs:71, received rpcs:20
2026-04-21 10:54:08.127500 license NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:08, duration:5 min, sent signals:62, received signals:1, sent rpcs:6, received rpcs:13
2026-04-21 10:54:08.280094 usb_entry NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:08, duration:5 min, sent signals:14, received signals:14, sent rpcs:12, received rpcs:7
2026-04-21 10:54:08.513118 rmcpd NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:08, duration:5 min, sent signals:92, received signals:16, sent rpcs:14, received rpcs:55
2026-04-21 10:54:09.294845 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:54:09.295644 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:54:09.298978 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:54:09.301066 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:54:09.382928 event_policy NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:09, duration:5 min, sent signals:75, received signals:5, sent rpcs:20, received rpcs:16
2026-04-21 10:54:09.433193 power_strategy NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:09, duration:5 min, sent signals:11, received signals:252, sent rpcs:43, received rpcs:3
2026-04-21 10:54:10.590748 product_mgmt NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:10, duration:5 min, sent signals:69, received signals:54, sent rpcs:13, received rpcs:83
2026-04-21 10:54:11.821030 account NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:11, duration:5 min, sent signals:148, received signals:2, sent rpcs:39, received rpcs:158
2026-04-21 10:54:12.822637 ipmi_core NOTICE: route_table_mgmt.lua(373): The numbers of ipmi_cmds in routing table are 796.
2026-04-21 10:54:17.937103 bios NOTICE: upgrade_executor.lua(267): [bios]upgrade chain: parse_bin (executor) start
2026-04-21 10:54:19.165891 web_backend NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:19, duration:5 min, sent signals:12, received signals:69, sent rpcs:28, received rpcs:6
2026-04-21 10:54:19.712963 bios NOTICE: bin_parser_period2.lua(123): 1 = {   updateSize = 5570560   updateAddr = 8388608 } 2 = {   updateSize = 393216   updateAddr = 14024704 } 3 = {   updateSize = 2359296   updateAddr = 14417920 }
2026-04-21 10:54:19.713279 bios NOTICE: bin_parser_period2.lua(156): unpack bios upgrade file successfully
2026-04-21 10:54:19.713727 bios NOTICE: upgrade_executor.lua(288): [bios]upgrade chain: select_channel (executor) start
2026-04-21 10:54:19.714055 bios NOTICE: upgrade_executor.lua(320): [bios]upgrade chain: upgrade_component (executor) start
2026-04-21 10:54:20.159175 redfish NOTICE: start_profiling.lua(151): profiling finished, start time:2026-04-21 10:49:20, duration:5 min, sent signals:30, received signals:58, sent rpcs:30, received rpcs:4
2026-04-21 10:54:20.285332 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-21 10:54:20.287299 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.290020 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 1, total block: 88
2026-04-21 10:54:20.317519 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-21 10:54:20.319226 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.321376 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 1, total block: 88
2026-04-21 10:54:20.345476 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 0 - 10240
2026-04-21 10:54:20.347060 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.348942 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 1, total block: 88
2026-04-21 10:54:20.418407 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-21 10:54:20.420687 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.422634 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 2, total block: 88
2026-04-21 10:54:20.448879 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-21 10:54:20.450520 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.452407 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 2, total block: 88
2026-04-21 10:54:20.478939 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 65536 - 75776
2026-04-21 10:54:20.480424 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.481968 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 2, total block: 88
2026-04-21 10:54:20.540065 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-21 10:54:20.541602 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.542824 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 3, total block: 88
2026-04-21 10:54:20.574517 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-21 10:54:20.575921 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.577092 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 3, total block: 88
2026-04-21 10:54:20.600184 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 131072 - 141312
2026-04-21 10:54:20.602004 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.603308 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 3, total block: 88
2026-04-21 10:54:20.663323 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-21 10:54:20.664380 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.665831 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 4, total block: 88
2026-04-21 10:54:20.694416 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-21 10:54:20.695621 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.697960 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 4, total block: 88
2026-04-21 10:54:20.724267 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 196608 - 206848
2026-04-21 10:54:20.725636 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.727186 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 4, total block: 88
2026-04-21 10:54:20.796650 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-21 10:54:20.797986 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.799486 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 5, total block: 88
2026-04-21 10:54:20.827816 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-21 10:54:20.830395 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.831881 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 5, total block: 88
2026-04-21 10:54:20.856562 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 262144 - 272384
2026-04-21 10:54:20.859891 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.861237 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 5, total block: 88
2026-04-21 10:54:20.927614 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 327680 - 337920
2026-04-21 10:54:20.931130 bios ERROR: spi_flash.lua(143): write data to spi flash failed
2026-04-21 10:54:20.934685 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 6, total block: 88
2026-04-21 10:54:20.970854 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 6, total block: 88
2026-04-21 10:54:21.004931 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 6, total block: 88
2026-04-21 10:54:21.060623 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 393216 - 403456
2026-04-21 10:54:21.062435 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 7, total block: 88
2026-04-21 10:54:21.093495 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 7, total block: 88
2026-04-21 10:54:21.122274 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 7, total block: 88
2026-04-21 10:54:21.183788 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 458752 - 468992
2026-04-21 10:54:21.184784 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 8, total block: 88
2026-04-21 10:54:21.215225 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 8, total block: 88
2026-04-21 10:54:21.247868 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 8, total block: 88
2026-04-21 10:54:21.310566 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 524288 - 534528
2026-04-21 10:54:21.311261 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 9, total block: 88
2026-04-21 10:54:21.336553 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 9, total block: 88
2026-04-21 10:54:21.368071 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 9, total block: 88
2026-04-21 10:54:21.426256 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 589824 - 600064
2026-04-21 10:54:21.427657 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 10, total block: 88
2026-04-21 10:54:21.459216 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 2cur_block: 10, total block: 88
2026-04-21 10:54:21.488455 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 3cur_block: 10, total block: 88
2026-04-21 10:54:21.548833 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 655360 - 665600
2026-04-21 10:54:21.551518 bios ERROR: spi_flash.lua(163): erase and write block flash failed, retry time: 1cur_block: 11, total block: 88
2026-04-21 10:54:21.672475 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 720896 - 731136
2026-04-21 10:54:21.795305 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 786432 - 796672
2026-04-21 10:54:21.926106 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 851968 - 862208
2026-04-21 10:54:22.061075 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 917504 - 927744
2026-04-21 10:54:22.192832 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 983040 - 993280
2026-04-21 10:54:22.316177 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1048576 - 1058816
2026-04-21 10:54:22.415698 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1114112 - 1124352
2026-04-21 10:54:22.527706 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1179648 - 1189888
2026-04-21 10:54:22.630489 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1245184 - 1255424
2026-04-21 10:54:22.755666 bios ERROR: spi_flash.lua(105): File does not seem to match flash data. First mismatch at 1310720 - 1320960
2026-04-21 10:54:22.890170 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=0, eth_name=eth0
2026-04-21 10:54:23.636833 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:54:23.637286 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 0, eth_name = eth0
2026-04-21 10:54:24.387554 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:54:24.389541 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=1, eth_name=eth0
2026-04-21 10:54:25.140707 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:54:25.141490 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 1, eth_name = eth0
2026-04-21 10:54:25.913560 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:54:25.916049 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:54:25.916346 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:54:26.667057 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:54:26.667366 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:54:26.670251 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:54:26.675631 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:54:28.247917 metric_analyzer NOTICE: metric_analyzer_app.lua(341): Start data collection task.
2026-04-21 10:54:31.949872 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 1 to flash successfully
2026-04-21 10:54:40.289554 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=0, eth_name=eth0
2026-04-21 10:54:40.722282 power_mgmt ERROR: power_mgmt_utils.lua(57): time service failed, psid: 2, error info: BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Eeprom_PsuChip2_0101, bus: I2c_3, write failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"addr":180,"mask":4294967295,"offset":250,"is_trace":false,"addrWidth":1,"len":6,"has_error":false,"type":1,"rw_type":0,"name":"Eeprom_PsuChip2_0101","buffer":"04 70 57 E7 69 10 ","offsetWidth":1,"requestor":"bmc.kepler.power_mgmt"}
2026-04-21 10:54:41.037248 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:54:41.038657 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 0, eth_name = eth0
2026-04-21 10:54:41.809829 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:54:41.811156 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=1, eth_name=eth0
2026-04-21 10:54:42.579772 network_adapter ERROR: ncsi_core.lua(64): ncsi: Enable channel failed.
2026-04-21 10:54:42.580198 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 1, eth_name = eth0
2026-04-21 10:54:43.332679 network_adapter ERROR: ncsi_core.lua(124): ncsi: Disable channel TX failed.
2026-04-21 10:54:43.334282 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:54:43.335382 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:54:44.349226 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 2 to flash successfully
2026-04-21 10:54:45.563295 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 3 to flash successfully
2026-04-21 10:54:50.406603 bios NOTICE: component_collection.lua(32): [bios]component upgrade: write region 4 to flash successfully
2026-04-21 10:54:50.448505 bios NOTICE: upgrade_executor.lua(335): [bios]upgrade chain: upgrade_component (executor) finish
2026-04-21 10:54:50.472810 bios NOTICE: upgrade_executor.lua(254): [bios]upgrade chain: decompress_file (executor) end
2026-04-21 10:54:50.478711 bios NOTICE: bios_object_mutihost.lua(123): [bios]start fetch component version info, system is 1
2026-04-21 10:54:50.894225 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-21 10:54:50.895683 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-21 10:54:50.909632 bios NOTICE: upgrade_executor.lua(230): [bios]upgrade chain: spi_driver (executor) end
2026-04-21 10:54:50.918443 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=false, timeout=1000, appname=Upgrade, reason=bios
2026-04-21 10:54:50.918984 fructrl NOTICE: pwr_on_lock.lua(71): [System:nil]Update item successfully, appname=(Upgrade), reason=(bios), pwronlocked=(false), timeout=(1000)
2026-04-21 10:54:50.921068 bios NOTICE: upgrade_executor.lua(167): [bios]upgrade chain: power_lock (executor) unlock
2026-04-21 10:54:50.922059 bios NOTICE: pfr_service.lua(317): [bios]pfr: system 1 no need wait bios effective
2026-04-21 10:54:50.923437 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PROCESS_START to PROCESS_FINISH
2026-04-21 10:54:50.938424 bios NOTICE: firmware_multihost.lua(225): [bios] clear activate mode(table: 0x5daab3df05c0), system id: 1
2026-04-21 10:54:51.113540 firmware_mgmt NOTICE: [worker](9): start action in worker
2026-04-21 10:54:51.183240 firmware_mgmt NOTICE: [worker](14): execute finish action script successfully
2026-04-21 10:54:51.536871 fructrl NOTICE: pwr_on_lock.lua(143): [System:nil]Delete pwr_on_lock item, appname=(Upgrade), reason=(bios)
2026-04-21 10:54:51.538392 fructrl NOTICE: pwr_on_lock.lua(149): [System:nil]PwrOnLocked has been unlocked
2026-04-21 10:54:52.206443 bios NOTICE: signal.lua(293): Start the bios upgrade finish phase
2026-04-21 10:54:52.208879 general_hardware ERROR: upgrade_subject.lua(124): [on_upgrade_finish] does not exists the observer, firmware_type:Bios
2026-04-21 10:54:52.209729 bios NOTICE: upgrade_service.lua(593): [bios]upgrade finish: start
2026-04-21 10:54:52.210523 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from PROCESS_FINISH to FIRMWARE_FINISHING
2026-04-21 10:54:52.211310 bios NOTICE: upgrade_state_machine.lua(83): [bios]state change from FIRMWARE_FINISHING to UPGRADE_READY
2026-04-21 10:54:52.212217 bios NOTICE: upgrade_service.lua(93): [bios]mode recover to Cold
2026-04-21 10:54:52.212987 bios NOTICE: upgrade_service.lua(597): [bios]hpm upgrade: bios package upgrade successfully
2026-04-21 10:54:52.233600 bios ERROR: upgrade_service.lua(140): [TPCM]refresh bios digest after upgrade bios failed!
2026-04-21 10:54:52.235980 bios NOTICE: upgrade_service.lua(575): [bios]FirmwareEffectiveStatus change to Effecting, system id : 1
2026-04-21 10:54:52.237014 bios NOTICE: pfr_service.lua(95): [PfrService]PfrService: try unlock fructl forever lock.
2026-04-21 10:54:52.362468 bios NOTICE: upgrade_service.lua(932): [BIOS]Start judge power status
2026-04-21 10:54:52.734688 fructrl NOTICE: fructrl_obj_mgnt.lua(264): [System:1]set poweron lock, pwronlocked=false, timeout=65535, appname=Upgrade, reason=VerifyFlash
2026-04-21 10:54:52.738234 bios NOTICE: pfr_service.lua(107): [PfrService]PfrService: unlock fructl forever lock success.
2026-04-21 10:55:00.723307 cooling NOTICE: mpc_server.lua(129): [MPC] Get cpu power model, params: -2057.0945511678 -10.474932593617 116.3243542473 -0.15803735552758 0.65418841692227 -2.1312179067992 0.0001952071071636 0.0018687695606837 -0.0067578703092244 0.013820205868635 [repeated 1 times in 0s from 2026-04-21 10:49:23.317450 to 2026-04-21 10:49:23.326547][flush]
2026-04-21 10:55:00.723724 cooling NOTICE: mpc_server.lua(129): [MPC] Get cpu power model, params: 402.32881208914 46.6230333 -46.417129 0.051951371 -1.64742783 1.5469615 0.000971813286 -0.00393266532 0.017608788 -0.0136075565 [repeated 1 times in 0s from 2026-04-21 10:49:23.331636 to 2026-04-21 10:49:23.370975][flush]
2026-04-21 10:55:00.724177 power_strategy NOTICE: base.lua(99): Sync object prop(NormalAndRedundancySupported): false [repeated 1 times in 7s from 2026-04-21 10:49:28.441023 to 2026-04-21 10:49:35.758981][flush]
2026-04-21 10:55:00.724581 power_strategy NOTICE: base.lua(99): Sync object prop(BackupCircuitVINStatus): 255 [repeated 1 times in 8s from 2026-04-21 10:49:28.444656 to 2026-04-21 10:49:36.241655][flush]
2026-04-21 10:55:00.724890 power_strategy NOTICE: base.lua(99): Sync object prop(SleepMode): [repeated 1 times in 8s from 2026-04-21 10:49:28.976740 to 2026-04-21 10:49:36.592279][flush]
2026-04-21 10:55:00.725274 power_strategy NOTICE: base.lua(99): Sync object prop(EquipmentMode): 255 [repeated 1 times in 7s from 2026-04-21 10:49:28.409516 to 2026-04-21 10:49:35.558759][flush]
2026-04-21 10:55:00.725573 power_strategy NOTICE: base.lua(99): Sync object prop(OutputVoltageFault): 0 [repeated 1 times in 6s from 2026-04-21 10:49:28.346416 to 2026-04-21 10:49:34.592344][flush]
2026-04-21 10:55:00.725857 power_strategy NOTICE: base.lua(99): Sync object prop(MainCircuitVINStatus): 255 [repeated 1 times in 8s from 2026-04-21 10:49:28.504166 to 2026-04-21 10:49:36.344490][flush]
2026-04-21 10:55:00.726198 power_strategy NOTICE: base.lua(99): Sync object prop(OutputState): 0 [repeated 1 times in 6s from 2026-04-21 10:49:28.292990 to 2026-04-21 10:49:34.286824][flush]
2026-04-21 10:55:00.726493 power_strategy NOTICE: base.lua(99): Sync object prop(PartNumber): [repeated 1 times in 4s from 2026-04-21 10:49:27.658987 to 2026-04-21 10:49:31.544205][flush]
2026-04-21 10:55:00.726780 power_strategy NOTICE: base.lua(99): Sync object prop(InputVoltageFault): 32768 [repeated 1 times in 5s from 2026-04-21 10:49:28.221120 to 2026-04-21 10:49:33.218910][flush]
2026-04-21 10:55:00.727054 power_strategy NOTICE: base.lua(99): Sync object prop(CommunicationStatus): 0 [repeated 1 times in 8s from 2026-04-21 10:49:28.518398 to 2026-04-21 10:49:36.404638][flush]
2026-04-21 10:55:00.727319 power_strategy NOTICE: base.lua(99): Sync object prop(RearPresence): 1 [repeated 81 times in 34s from 2026-04-21 10:49:29.853769 to 2026-04-21 10:50:03.836074][flush]
2026-04-21 10:55:00.727599 power_strategy NOTICE: base.lua(99): Sync object prop(Health): 255 [repeated 1 times in 8s from 2026-04-21 10:49:28.637983 to 2026-04-21 10:49:36.586862][flush]
2026-04-21 10:55:00.727931 power_strategy NOTICE: base.lua(99): Sync object prop(IsUpgrading): false [repeated 1 times in 6s from 2026-04-21 10:49:28.354206 to 2026-04-21 10:49:35.012435][flush]
2026-04-21 10:55:00.728215 power_strategy NOTICE: base.lua(99): Sync object prop(ScanStatus): 0 [repeated 1 times in 5s from 2026-04-21 10:49:27.927358 to 2026-04-21 10:49:32.766403][flush]
2026-04-21 10:55:00.728643 thermal_mgmt WARNING: dev_object_manage.lua(167): cannot find adapter, object_name: CoolingRequirement_1_01013B [repeated 16 times in 46s from 2026-04-21 10:49:21.247315 to 2026-04-21 10:50:07.062099][flush]
2026-04-21 10:55:01.351822 chassis NOTICE: chassis_object.lua(183): name = Memory, connector_num = 0, device_num = 32 [repeated 9 times in 4s from 2026-04-21 10:49:58.571079 to 2026-04-21 10:50:02.798643][flush]
2026-04-21 10:55:08.619274 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:55:08.619864 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:55:08.622643 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:55:08.624845 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:55:22.197046 network_adapter NOTICE: ncsi_core.lua(60): ncsi: Enable channel. package_id=0, channel_d=0, eth_name=eth0
2026-04-21 10:55:22.955283 network_adapter NOTICE: ncsi_core.lua(120): ncsi: Disable channel TX. package_id = 0, channel_d = 0, eth_name = eth0
2026-04-21 10:55:25.211059 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:55:25.211771 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:55:25.967415 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:55:25.967770 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:55:25.971180 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:55:25.976448 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:55:42.598948 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:55:42.599536 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:55:54.950530 sensor NOTICE: sel_management.lua(688): add sel[{"RecordId":1807,"SelEventType":111,"SelData3":0,"SelData2":31,"SelData1":0,"RecordSeq":1831,"SubjectName":"MainBoard","SensorName":"Mngmnt Health","SensorId":"DiscreteSensor_MngmntHealth_00","SensorType":40,"SensorNumber":3,"SelMsgVersion":4,"GenerateId":32,"Timestamp":1776768954,"SelType":2}] successfully, record id is 1807
2026-04-21 10:55:54.951033 sensor NOTICE: sensor_instance.lua(263): [DiscreteSensor_MngmntHealth_00] assert an event [event dir: 39]
2026-04-21 10:55:54.958432 redfish NOTICE: alarm.lua(644): received a sel[1831]
2026-04-21 10:55:54.957908 event_policy NOTICE: synchronizer.lua(281): received a sel[1831]
2026-04-21 10:55:55.945856 sensor NOTICE: sel_management.lua(688): add sel[{"RecordId":1808,"SelEventType":111,"SelData3":0,"SelData2":32,"SelData1":0,"RecordSeq":1832,"SubjectName":"MainBoard","SensorName":"Mngmnt Health","SensorId":"DiscreteSensor_MngmntHealth_00","SensorType":40,"SensorNumber":3,"SelMsgVersion":4,"GenerateId":32,"Timestamp":1776768955,"SelType":2}] successfully, record id is 1808
2026-04-21 10:55:55.946510 sensor NOTICE: sensor_instance.lua(263): [DiscreteSensor_MngmntHealth_00] assert an event [event dir: 39]
2026-04-21 10:55:55.954009 redfish NOTICE: alarm.lua(644): received a sel[1832]
2026-04-21 10:55:55.953506 event_policy NOTICE: synchronizer.lua(281): received a sel[1832]
2026-04-21 10:56:07.904727 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:56:07.905357 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:56:07.909138 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:56:07.915501 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:56:24.483474 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:56:24.483992 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:56:25.261716 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:56:25.262027 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:56:25.264475 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:56:25.266040 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:56:33.580716 network_adapter ERROR: ncsi_package.lua(134): ncsi cmd ctrl select package failed, package_id = 1, channel_id = 31, eth_name = eth0 [repeated 61 times in 301s from 2026-04-21 10:51:32.706537 to 2026-04-21 10:56:33.580716]
2026-04-21 10:56:35.075946 network_adapter ERROR: ncsi_package.lua(134): ncsi cmd ctrl select package failed, package_id = 0, channel_id = 31, eth_name = eth0 [repeated 61 times in 301s from 2026-04-21 10:51:34.231394 to 2026-04-21 10:56:35.075946]
2026-04-21 10:56:41.861396 network_adapter ERROR: ncsi_comm.lua(277): ncsi: Get db nc info fail.(port_id = 255)
2026-04-21 10:56:41.861866 network_adapter NOTICE: ncsi_comm.lua(330): ncsi: Active port id is invalid.(port_id = 255)
2026-04-21 10:56:52.172380 oms NOTICE: task_mgmt.lua(287): Create task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 0, State: New] successfully
2026-04-21 10:56:52.278100 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 0, State: Running] successfully
2026-04-21 10:56:52.420135 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 10, State: Running] successfully
2026-04-21 10:56:54.755420 bmc_soc NOTICE: uart_data.lua(734): start collecting all com logs
2026-04-21 10:56:56.087921 bmc_soc NOTICE: uart_data.lua(768): all com logs have been compressed
2026-04-21 10:56:56.087646 bios NOTICE: log_collector.lua(98): [bios]start to dump bios log
2026-04-21 10:56:56.088082 bios NOTICE: log_collector.lua(73): [bios]start collect bios info
2026-04-21 10:56:57.181941 bmc_network NOTICE: network_dump.lua(132): bmc_network dump begin.
2026-04-21 10:56:57.344193 event NOTICE: event_app.lua(293): event dump is started.
2026-04-21 10:56:57.449565 bmc_network NOTICE: network_dump.lua(142): bmc_network dump end.
2026-04-21 10:56:57.510228 fusionpod NOTICE: debug.lua(823): dump bmc_network/service/fusionpod rpc count records success
2026-04-21 10:56:58.755858 ras ERROR: file_securec.c(763): change the owner and group of dest_path failed, errno [1: Operation not permitted]
2026-04-21 10:56:58.756942 fault_diagnosis ERROR: fdm_dump.lua(38): copy file fail: -1
2026-04-21 10:56:58.758250 fault_diagnosis NOTICE: fdm_dump.lua(98): per_temporary.db dump completed
2026-04-21 10:56:58.766796 ras ERROR: file_securec.c(763): change the owner and group of dest_path failed, errno [1: Operation not permitted]
2026-04-21 10:56:58.768092 fault_diagnosis ERROR: fdm_dump.lua(38): copy file fail: -1
2026-04-21 10:56:58.769307 fault_diagnosis NOTICE: fdm_dump.lua(98): per_reset.db dump completed
2026-04-21 10:56:59.026042 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 23, State: Running] successfully
2026-04-21 10:57:00.288537 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 25, State: Running] successfully
2026-04-21 10:57:00.472622 general_hardware NOTICE: unit_manager.lua(642): unit_manager:on_dump_cb start.
2026-04-21 10:57:00.479298 ipmi_core NOTICE: ipmi_dump.lua(53): ipmi_core dump begin.
2026-04-21 10:57:00.561337 ipmi_core NOTICE: ipmi_dump.lua(33): dump_route_table collect start.
2026-04-21 10:57:00.563726 general_hardware ERROR: unit.lua(450): SMC read (get software version) fail
2026-04-21 10:57:00.564198 general_hardware ERROR: unit.lua(477): CpuBoard1 get_dfx_info fail
2026-04-21 10:57:00.630638 unknown_service NOTICE: debug.lua(823): dump ipmi_core/service/ipmb rpc count records success
2026-04-21 10:57:00.663040 unknown_service NOTICE: debug.lua(823): dump ipmi_core/service/edma rpc count records success
2026-04-21 10:57:00.693078 unknown_service NOTICE: debug.lua(823): dump ipmi_core/service/bt rpc count records success
2026-04-21 10:57:00.702775 general_hardware ERROR: unit.lua(461): SMC read (get dfx info) fail
2026-04-21 10:57:00.703082 general_hardware ERROR: unit.lua(477): ExpBoard1 get_dfx_info fail
2026-04-21 10:57:00.730574 ipmi_core NOTICE: ipmi_dump.lua(46): dump_route_table collect end.
2026-04-21 10:57:00.732438 ipmi_core NOTICE: ipmi_dump.lua(96): ipmi_core dump end.
2026-04-21 10:57:00.737611 general_hardware ERROR: unit.lua(461): SMC read (get dfx info) fail
2026-04-21 10:57:00.738027 general_hardware ERROR: unit.lua(477): FanBoard1 get_dfx_info fail
2026-04-21 10:57:00.741827 general_hardware NOTICE: unit_manager.lua(722): EXP board info  collect finish
2026-04-21 10:57:00.743699 general_hardware NOTICE: unit_manager.lua(722): CPU board Info  collect finish
2026-04-21 10:57:00.745472 general_hardware NOTICE: unit_manager.lua(722): FAN board Info  collect finish
2026-04-21 10:57:00.747248 general_hardware NOTICE: mcu_service.lua(206): mcu info collect finish
2026-04-21 10:57:00.768327 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:00.981045 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:01.369180 om ERROR: alm_callback.c(789): [license][alm] 0001[TIME]2026-04-21 10:57:01 lgen-ck err--350: Prd[1] ALM_LicGeneralQuery end 2030043238
2026-04-21 10:57:01.369806 license ERROR: license_dump.lua(112): Get revoke ticket from db failed
2026-04-21 10:57:01.371589 om ERROR: alm_callback.c(789): [license][alm] 0002[TIME]2026-04-21 10:57:01 lgen-ck err--350: Prd[1] ALM_LicGeneralQuery end 2030043238
2026-04-21 10:57:01.372212 license ERROR: license_dump.lua(65): failed to get feature key info, ret = 0x79000066
2026-04-21 10:57:01.474202 om ERROR: alm_callback.c(789): [license][alm] 0003[TIME]2026-04-21 10:57:01 lgen-ck err--350: Prd[1] ALM_LicGeneralQuery end 2030043238
2026-04-21 10:57:01.484435 license NOTICE: init.lua(79): register to bus for class, error name: kepler.class.NullObjectName
2026-04-21 10:57:01.738800 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 28, State: Running] successfully
2026-04-21 10:57:01.980692 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:02.142614 hardware ERROR: mctp_dump.cpp(40): Failed to open /dev/mem
2026-04-21 10:57:02.149648 mctpd NOTICE: mctp_dump.lua(91): mctp info collect finish
2026-04-21 10:57:02.214796 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:02.385841 frudata ERROR: fru_dump.lua(127): get_ref_frudata_obj error
2026-04-21 10:57:02.421912 unknown_service NOTICE: debug.lua(823): dump mctpd/service/smbus_write_read_service rpc count records success
2026-04-21 10:57:02.992983 unknown_service NOTICE: debug.lua(823): dump mctpd/service/write_service rpc count records success
2026-04-21 10:57:03.046007 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 30, State: Running] successfully
2026-04-21 10:57:03.069494 network_adapter NOTICE: log_netcard_info.lua(149): log_dump_cb: collect netcard info
2026-04-21 10:57:03.069853 network_adapter NOTICE: log_netcard_info.lua(93): start collect netcard info
2026-04-21 10:57:03.073489 metric_analyzer NOTICE: metric_dump.lua(90): metric.db dump completed
2026-04-21 10:57:03.075412 metric_analyzer NOTICE: metric_dump.lua(90): per_poweroff.db dump completed
2026-04-21 10:57:03.091054 metric_analyzer NOTICE: metric_dump.lua(90): per_reset.db dump completed
2026-04-21 10:57:03.081199 network_adapter ERROR: log_netcard_info.lua(110): network info is empty, nothing to log
2026-04-21 10:57:03.135315 network_adapter NOTICE: log_netcard_info.lua(154): finish to dump net card info log
2026-04-21 10:57:03.135866 network_adapter NOTICE: network_adapter.lua(1876): optical module cnt is 0
2026-04-21 10:57:03.136339 network_adapter NOTICE: network_adapter.lua(1913): netcard cnt is 0
2026-04-21 10:57:03.136633 network_adapter NOTICE: network_adapter.lua(1939): netport cnt is 0
2026-04-21 10:57:03.203758 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","addr":96,"requestor":"bmc.kepler.web_backend","mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:03.303080 frudata ERROR: fru_dump.lua(182): dump_get_fruinfo failed
2026-04-21 10:57:03.393287 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:03.994358 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:04.196885 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:04.262415 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 34, State: Running] successfully
2026-04-21 10:57:04.775222 pcie_device NOTICE: biz_topo.lua(1243): [BizTopo] cable log dump.
2026-04-21 10:57:04.797274 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:05.015513 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:05.193538 power_mgmt NOTICE: log_service.lua(155): collect power_mgmt log start
2026-04-21 10:57:05.205759 event NOTICE: event_common.lua(1020): start clear database info
2026-04-21 10:57:05.293345 redfish NOTICE: event.lua(537): redfish dump is started
2026-04-21 10:57:05.297330 redfish NOTICE: event.lua(550): redfish dump is completed
2026-04-21 10:57:05.612809 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:05.714520 event NOTICE: event_common.lua(1024): finish clear database info
2026-04-21 10:57:05.714813 event NOTICE: event_app.lua(323): event dump is completed.
2026-04-21 10:57:05.671021 redfish NOTICE: debug.lua(823): dump route_mapper/worker_service/main rpc count records success
2026-04-21 10:57:05.808588 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:05.892137 remote_console NOTICE: dump.lua(51): remote_console dump begin
2026-04-21 10:57:06.107074 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 36, State: Running] successfully
2026-04-21 10:57:06.219048 unknown_service NOTICE: debug.lua(823): dump remote_console/service/vmm_client rpc count records success
2026-04-21 10:57:06.249349 unknown_service NOTICE: debug.lua(823): dump remote_console/service/videoplay_agent rpc count records success
2026-04-21 10:57:06.315919 unknown_service NOTICE: debug.lua(823): dump remote_console/service/console_agent rpc count records success
2026-04-21 10:57:06.340076 unknown_service NOTICE: debug.lua(823): dump remote_console/service/vmm_agent rpc count records success
2026-04-21 10:57:06.366624 unknown_service NOTICE: debug.lua(823): dump remote_console/service/vmm_core rpc count records success
2026-04-21 10:57:06.410586 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:06.603269 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:07.203245 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 41, State: Running] successfully
2026-04-21 10:57:07.209209 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:07.214755 network_adapter NOTICE: ncsi_comm.lua(59): Failed to obtain LinkStatus for 3 consecutive times, need to relink.
2026-04-21 10:57:07.216336 network_adapter NOTICE: ncsi_service.lua(448): [ncsi_service], sig relink ncsi port.
2026-04-21 10:57:07.228615 network_adapter NOTICE: ncsi_comm.lua(393): ncsi: Init ncsi port.
2026-04-21 10:57:07.247873 network_adapter NOTICE: ncsi_comm.lua(248): ncsi: Basic init, eth name = eth0
2026-04-21 10:57:07.405212 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:07.494636 storage NOTICE: storage_app.lua(67): Dumping bios_boot_stage
2026-04-21 10:57:07.508066 storage NOTICE: storage_app.lua(69): Dumping controllers info
2026-04-21 10:57:08.004646 unknown_service NOTICE: debug.lua(823): dump storage/service/smld rpc count records success
2026-04-21 10:57:08.012262 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:08.225646 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:08.304158 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 43, State: Running] successfully
2026-04-21 10:57:08.807885 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:09.012763 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D5 00 FE ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:09.212119 web_backend NOTICE: debug.lua(823): dump route_mapper/worker_service/main rpc count records success
2026-04-21 10:57:09.400322 oms NOTICE: task_mgmt.lua(418): Update task[Id: 1955770804, StartTime: 2026-04-21T10:56:52+00:00, Progress: 45, State: Running] successfully
2026-04-21 10:57:09.607604 general_hardware ERROR: smc_interface.lua(502): SMC read (vrd dump specification) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/apps/hwproxy/lualib/hwproxy_objects/app_bus.lua:104: ...bmc/apps/hwproxy/lualib/hwproxy_objects/work_objects.lua:117: chip: Smc_CpuBrdSMC_010101, bus: I2c_1, read failed: i2c.lua:117: response error, i2c write fail, ret: 5, input:{"is_trace":false,"type":1,"has_error":false,"rw_type":0,"drv_write_delay":0,"len":6,"buffer":"04 0C 03 D9 00 02 ","offsetWidth":1,"name":"Smc_CpuBrdSMC_010101","requestor":"bmc.kepler.web_backend","addr":96,"mask":4294967295,"smc_target":1,"offset":32,"addrWidth":1}
2026-04-21 10:57:09.799814 general_hardware ERROR: smc_interface.lua(529): SMC read (vrd dump) fail, error:BMC.Error.Unknow: ./opt/bmc/libmc/lualib/mc/context.lua:196: ./opt/bmc/libmc/lualib/sd_bus/object.lua:314: ./opt/bmc/ap
4

下面是dmesg的日志,298之后是升级时新增的日志，

dmesg
[   77.341975] device-mapper: ioctl: dmsetup[2963]: dm-0 (mmcblksp) is removed successfully
[   77.708574] device-mapper: ioctl: dmsetup[2970]: dm-0 (mmcblksp) is created successfully
[   79.281182] 69,2026-04-21 10:49:03,2798,mctp_reset,1477,reset mctp ok!
[   79.306704] 70,2026-04-21 10:49:03,2798,mctp_dereset,1501,dereset mctp ok!
[   86.413459] IPv6: ADDRCONF(NETDEV_CHANGE): veth: link becomes ready
[   96.053345] usbcore: registered new interface driver cdc_ether
[   97.872825] usbcore: registered new interface driver rndis_host
[  104.404583] usb device-0: command connect. function count 2
[  104.627283] usb device-0: attach driver
[  104.627329] usb device-0: gadget bind
[  104.627343] usb device-0: Bind speed 2.0
[  104.639302] usb device-0: gadget suspend
[  104.952060] usb device-0: setup-request[T:8][0]:0x80 0x06 0x00 0x01 0x00 0x00 0x08 0x00
[  104.952237] usb device-0: setup-request[T:8][0]:0x80 0x06 0x00 0x01 0x00 0x00 0x12 0x00
[  104.952507] usb device-0: setup-request[T:8][0]:0x80 0x06 0x00 0x02 0x00 0x00 0x09 0x00
[  104.952748] usb device-0: setup-request[T:8][0]:0x80 0x06 0x00 0x02 0x00 0x00 0x3b 0x00
[  104.953008] usb device-0: setup-request[T:8][0]:0x80 0x06 0x00 0x03 0x00 0x00 0xff 0x00
[  104.953259] usb device-0: setup-request[T:8][0]:0x80 0x06 0x01 0x03 0x09 0x04 0xff 0x00
[  104.953511] usb device-0: setup-request[T:8][0]:0x80 0x06 0x02 0x03 0x09 0x04 0xff 0x00
[  104.953878] usb device-0: setup-request[T:8][0]:0x00 0x09 0x01 0x00 0x00 0x00 0x00 0x00
[  104.953901] usb device-0: setup configuration. gadget state <6>
[  104.953914] usb device-0: Keyboard configured
[  104.953962] usb device-0: Mouse configured
[  104.954138] usb device-0: setup-request[T:8][0]:0x80 0x06 0x02 0x03 0x09 0x04 0xff 0x00
[  104.954395] usb device-0: setup-request[T:8][0]:0x21 0x0a 0x00 0x00 0x00 0x00 0x00 0x00
[  104.954481] usb device-0: setup-request[T:8][0]:0x81 0x06 0x00 0x22 0x00 0x00 0x3f 0x00
[  104.954787] usb device-0: setup-request[T:8][0]:0x21 0x09 0x00 0x02 0x00 0x00 0x01 0x00
[  105.022240] usb device-0: setup-request[T:8][0]:0x80 0x06 0x02 0x03 0x09 0x04 0xff 0x00
[  105.022519] usb device-0: setup-request[T:8][0]:0x21 0x0a 0x00 0x00 0x01 0x00 0x00 0x00
[  105.022613] usb device-0: setup-request[T:8][0]:0x81 0x06 0x00 0x22 0x01 0x00 0x3c 0x00
[  105.263661] usb device-0: setup-request[T:8][0]:0x21 0x09 0x00 0x02 0x00 0x00 0x01 0x00
[  115.956029] [I2C-03-RT<-5|-5>] M<0x5a|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x8> I<0x0|0x710|0x0>
[  117.846905] 71,2026-04-21 10:49:41,3544,bt_probe,781,bt use LPC!
[  117.857877] 72,2026-04-21 10:49:41,3544,bt_probe,806,bt init ok!
[  130.811289] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|2|0> C<1|0|2> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  136.007805] 73,2026-04-21 10:49:59,2798,mctp_reset,1477,reset mctp ok!
[  136.092765] 74,2026-04-21 10:50:00,2798,mctp_dereset,1501,dereset mctp ok!
[  168.252297] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  185.579169] 75,2026-04-21 10:50:49,ISR,sysctrl_rst_int_handle,436,Receive subsys_rst_irq(42), int_reg(0x13c) int_sts(0x407f)!
[  185.590479] 76,2026-04-21 10:50:49,ISR,sysctrl_rst_int_handle,436,Receive subsys_rst_irq(41), int_reg(0x13c) int_sts(0x417b)!
[  185.755461] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  186.157441] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  186.517737] usb device-0: gadget disconnect
[  186.517764] usb device-0: reset configuration. gadget state <7>
[  186.517779] usb device-0: Keyboard disabled
[  186.517790] usb device-0: Mouse disabled
[  186.768219] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.290044] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|2|0> C<1|0|2> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.370020] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.383377] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.573775] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.777376] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.794038] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  187.981773] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x510|0x0>
[  188.389614] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  188.405458] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  188.592945] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x510|0x0>
[  188.999723] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  189.161671] 77,2026-04-21 10:50:53,2743,mctp_reset,1477,reset mctp ok!
[  189.169944] 78,2026-04-21 10:50:53,2743,mctp_dereset,1501,dereset mctp ok!
[  189.213048] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  189.236708] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  189.621680] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  190.235520] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  190.428945] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  190.633217] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  191.446114] [I2C-01-RT<-5|-5>] M<0x30|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x1> I<0x0|0x510|0x0>
[  195.687151] edma: 1862, host is lost.
[  202.729314] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  215.370614] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|2|0> C<1|0|2> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  261.208503] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  267.049085] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  268.652368] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x510|0x0>
[  298.092115] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  342.168917] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  361.607069] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|2|0> C<1|0|2> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  368.651386] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  382.626194] 79,2026-04-21 10:54:06,5740,hisfc_drv_probe,834,probe bus 0
[  382.635247] 80,2026-04-21 10:54:06,5740,hisfc_drv_request_permission,628,sfc0 use hwid 4
[  382.643897] 81,2026-04-21 10:54:06,5740,hisfc_flash_scan_init,1050,hisfc_probe start bus 0
[  382.652448] 82,2026-04-21 10:54:06,5740,sfc_sys_set_controller_clk,246,bus 0 clock frequency of is all set!
[  382.662603] 83,2026-04-21 10:54:06,5740,sfc_sys_clock_operator,213,CLOSE 1711 SFC Clock Success!
[  382.673637] 84,2026-04-21 10:54:06,5740,sfc_sys_clock_operator,223,Open 1711 SFC Clock Success!
[  382.682995] 85,2026-04-21 10:54:06,5740,sfc_core_spi_probe,2053,Spi(cs0) ID: 0x00000000 0x00000000
[  382.692430] 86,2026-04-21 10:54:06,5740,sfc_core_spi_probe,2056,Spi(cs0): RDID not right!
[  382.704733] 87,2026-04-21 10:54:06,5740,sfc_core_spi_probe,2053,Spi(cs1) ID: 0x82252882 0x25288225
[  382.713943] 88,2026-04-21 10:54:06,5740,sfc_spi_search_rw,125,dump[1] isread(1) iftype:1
[  382.722105] 89,2026-04-21 10:54:06,5740,sfc_spi_search_rw,125,dump[1] isread(0) iftype:1
[  382.730605] 90,2026-04-21 10:54:06,5740,sfc_core_show_spi,1690,Spi(cs 1):
[  382.737577] 91,2026-04-21 10:54:06,5740,sfc_core_show_spi,1691,Name:"default default"
[  382.770003] Creating 1 MTD partitions on "hi_sfc0.1":
[  382.775187] 0x000000000000-0x000008000000 : "sfc0cs1"
[  382.887420] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  416.719408] [I2C-03-RT<-5|-5>] M<0x5a|0x0|0x0|3|10> L<7|0|0> C<7|0|0> E<0x1|0x0|0x0|0x8> I<0x0|0x710|0x0>
[  426.540682] 92,2026-04-21 10:54:50,5912,hisfc_drv_remove,888,hisfc_drv_remove
[  426.549027] 93,2026-04-21 10:54:50,5912,hisfc_drv_remove,896,hisfc_drv_remove bus 0
[  426.559159] Deleting MTD partitions on "hi_sfc0.1":
[  426.559183] Deleting sfc0cs1 MTD partition
[  427.769077] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  452.406385] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
[  460.649503] [I2C-03-RT<-5|-5>] M<0x5a|0x1|0x0|1|10> L<1|3|0> C<1|0|3> E<0x801|0x0|0x0|0x1> I<0x0|0x710|0x0>
5

下面是firmware_mgmt的debug级别日志


% dloglevel debug

% dlogtype local
2026-04-21 10:53:47.609779 firmware_mgmt NOTICE: debug.lua(460): Set debug log output type to (local) successfully
2026-04-21 10:53:47.612008 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:53:47.614033 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34a8bab6a0] exit
Success

% 2026-04-21 10:53:47.617118 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:02.411277 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:02.413926 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:02.418273 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:02.420146 firmware_mgmt NOTICE: active_fructl.lua(95): get host type is Singlehost
2026-04-21 10:54:02.420990 firmware_mgmt NOTICE: utils.lua(36): The file path is Local.
2026-04-21 10:54:02.424533 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
2026-04-21 10:54:02.426206 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:54:02.428386 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'
2026-04-21 10:54:02.429437 firmware_mgmt NOTICE: init.lua(79): Upgrading_Flag is true
2026-04-21 10:54:02.436281 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
2026-04-21 10:54:02.439547 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
2026-04-21 10:54:02.440987 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/
2026-04-21 10:54:02.443201 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34a8bab6a0] exit
2026-04-21 10:54:02.449423 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:54:02.450369 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34a8bab6a0] exit
2026-04-21 10:54:02.451572 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34a8bab6a0]
2026-04-21 10:54:02.453759 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348fc2f588]
2026-04-21 10:54:02.462729 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
2026-04-21 10:54:02.467527 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348fc2f588] exit
2026-04-21 10:54:02.468288 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348fc2f588]
2026-04-21 10:54:02.469430 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f349c1f9798]
2026-04-21 10:54:02.471723 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f349c1f9798] exit
2026-04-21 10:54:02.472617 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348fc2f588] exit
2026-04-21 10:54:02.473374 firmware_mgmt NOTICE: init.lua(40): update status to FS_SIMPLE_UPGRADING.
2026-04-21 10:54:02.475596 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], interface[bmc.kepler.TaskService.Task], name[Id], value[nil]->[2866844768], 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
2026-04-21 10:54:02.477786 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:02.479999 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], interface[bmc.kepler.TaskService.Task], name[StartTime], value[nil]->["2026-04-21T10:54:02+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/lual
2026-04-21 10:54:02.481815 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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 f
2026-04-21 10:54:02.483996 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:02.486172 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:02.488260 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:02.490326 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:02.492222 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:02.494109 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:02.496302 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:02.498242 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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/log
2026-04-21 10:54:02.500470 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.lu
2026-04-21 10:54:02.505299 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f348fdb25a8
2026-04-21 10:54:02.512226 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f34b2155118
2026-04-21 10:54:02.517046 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.l
2026-04-21 10:54:02.518845 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f34b2156bd0
2026-04-21 10:54:02.520902 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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/l
2026-04-21 10:54:02.523238 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.l
2026-04-21 10:54:02.527765 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f34a49c2a90
2026-04-21 10:54:02.530604 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f34a8b37b00
2026-04-21 10:54:02.534470 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.
2026-04-21 10:54:02.536062 firmware_mgmt DEBUG: object.lua(83): invoke log function failed, err: table: 0x2f34b2156bd0
2026-04-21 10:54:02.538354 firmware_mgmt NOTICE: task_mgmt.lua(287): Create task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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_upgrad
2026-04-21 10:54:02.541135 firmware_mgmt NOTICE: task_service.lua(59): task create success, task id: 2866844768
2026-04-21 10:54:02.542090 firmware_mgmt NOTICE: task_id_mgmt.lua(30): add serial task id(2866844768) successfully
2026-04-21 10:54:02.543081 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f349c1f9798]
2026-04-21 10:54:02.544364 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:02.545325 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
2026-04-21 10:54:02.545959 firmware_mgmt NOTICE: tasks_scheduling.lua(121): start tasks processer
2026-04-21 10:54:02.546631 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:1, process:0
2026-04-21 10:54:02.548647 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:02.549668 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:02.650482 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:25
2026-04-21 10:54:02.651821 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:02.653401 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:25
2026-04-21 10:54:02.655319 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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_eas
2026-04-21 10:54:02.712239 firmware_mgmt NOTICE: file_transfer.lua(141): start to move file [S920S10-KL4.41.102.260324.R.CMS_0831517.hpm] from tmp to shm
2026-04-21 10:54:02.802099 firmware_mgmt NOTICE: file_transfer.lua(146): move_file_s ok:true, err:0
2026-04-21 10:54:03.003114 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
2026-04-21 10:54:03.080412 firmware_mgmt NOTICE: validate_sign.lua(195): verify signature successfully
2026-04-21 10:54:03.082092 firmware_mgmt NOTICE: action.lua(37): Validate signature successfully
2026-04-21 10:54:03.084762 firmware_mgmt NOTICE: hpm_package.lua(757): ManufacturerValidateEnabled is false, there is no need to validate manufacture_id.
2026-04-21 10:54:03.260174 firmware_mgmt NOTICE: hpm_package.lua(562): parse cfg file successfully, Version:1.0 FileNum:2
2026-04-21 10:54:03.262225 firmware_mgmt NOTICE: hpm_package.lua(450): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:03.264216 firmware_mgmt NOTICE: hpm_package.lua(457): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:03.264985 firmware_mgmt NOTICE: hpm_package.lua(468): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:03.265930 firmware_mgmt NOTICE: hpm_package.lua(415): System product info:ProductId(0), ProductVendorID(0x00000001), ProductUniqueID(0x030ABF00)
2026-04-21 10:54:03.266637 firmware_mgmt NOTICE: hpm_package.lua(329): check product id successfully
2026-04-21 10:54:03.267264 firmware_mgmt INFO: hpm_package.lua(352): cfg_uid = 1030abf00
2026-04-21 10:54:03.267968 firmware_mgmt NOTICE: hpm_package.lua(354): check product uid successfully
2026-04-21 10:54:03.268697 firmware_mgmt NOTICE: hpm_package.lua(443): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:03.269830 firmware_mgmt NOTICE: hpm_package.lua(494): hard_revision:0, soft_revision:0
2026-04-21 10:54:03.271289 firmware_mgmt NOTICE: hpm_package.lua(507): revision number check successfully. Target revision=(0, 0) and hpm revision=1
2026-04-21 10:54:03.275456 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:03.278494 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:03.280062 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:03.281029 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:03.369823 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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/l
2026-04-21 10:54:03.371497 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:03.373471 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.
2026-04-21 10:54:03.375982 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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
2026-04-21 10:54:03.507253 firmware_mgmt NOTICE: action.lua(47): Parse hpm package successfully
2026-04-21 10:54:03.842547 firmware_mgmt NOTICE: task_instance.lua(217): upgrade_task file_name=S920S10-KL4.41.102.260324.R.CMS_0831517.hpm, FirmwareType=Bios, fw_num=1, UniqueIDList=table: 0x2f348c90f5d0, sys_id=1, info_key=1_Bios_2866844768
2026-04-21 10:54:03.844785 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:03.849910 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:03.853076 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:03.856919 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:03.858105 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:03.858834 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:03.859774 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:03.863653 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:03.952266 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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_in
2026-04-21 10:54:03.953768 firmware_mgmt NOTICE: info_mgmt.lua(82): create_info: info_key=1_Bios_2866844768, FirmwareType=Bios, task_id=2866844768, upg_fw_num=1
2026-04-21 10:54:03.957331 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:03.959655 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:03.962243 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:03.964433 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:03.969367 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:03.971664 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:03.972450 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:04.025675 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:04.029123 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:04.036308 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:04.041144 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f348c5a2d70] exit
2026-04-21 10:54:04.062704 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:04.064546 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f348c5a2d70]
2026-04-21 10:54:04.065812 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
2026-04-21 10:54:04.066771 firmware_mgmt NOTICE: task_instance.lua(662): firmware(info key:1_Bios_2866844768) do upgrade stages
2026-04-21 10:54:04.067719 firmware_mgmt NOTICE: task_instance.lua(295): public initialize action start
2026-04-21 10:54:04.068639 firmware_mgmt NOTICE: hpm_package.lua(479): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:04.069497 firmware_mgmt NOTICE: hpm_package.lua(519): now uptime = 381, firmware init time = 0
2026-04-21 10:54:04.070680 firmware_mgmt NOTICE: hpm_package.lua(450): get obj table: 0x2f34aeac5bb8 for Id=2
2026-04-21 10:54:04.071409 firmware_mgmt NOTICE: task_instance.lua(300): public initialize action end
2026-04-21 10:54:04.072490 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: INITIALIZE -> DIFF_PREPARE, 5
2026-04-21 10:54:04.076141 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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 fun
2026-04-21 10:54:04.078389 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:04.083780 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:04.085948 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:04.089893 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:04.093095 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:04.094536 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:04.183385 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.l
2026-04-21 10:54:04.185153 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:04.186519 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:25
2026-04-21 10:54:04.188968 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:04.198159 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:04.203113 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:04.206923 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:04.207868 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:04.565548 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:04.567925 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:04.658939 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:04.660038 firmware_mgmt NOTICE: info_mgmt.lua(393): set FirmwareMode to Single
2026-04-21 10:54:04.660794 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: DIFF_PREPARE -> COMMON_PREPARE, 5
2026-04-21 10:54:04.688711 firmware_mgmt NOTICE: action.lua(86): public prepare action start
2026-04-21 10:54:04.764232 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:04.766042 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.056476 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:05.271733 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.274540 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.311923 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.313721 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.352622 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.354783 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.383164 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.384969 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.561852 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.563412 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.567466 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.569426 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.727450 firmware_mgmt NOTICE: action.lua(92): public prepare action end
2026-04-21 10:54:05.728395 firmware_mgmt NOTICE: task_instance.lua(673): upgrade FirmwareMode Single
2026-04-21 10:54:05.828377 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:2
2026-04-21 10:54:05.830466 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.832489 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:25
2026-04-21 10:54:05.834595 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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_s
2026-04-21 10:54:05.835537 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: COMMON_PREPARE -> PROCESS, 15
2026-04-21 10:54:05.838225 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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 fu
2026-04-21 10:54:05.840822 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:05.844369 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:05.847147 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:05.852178 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.939809 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:05.940617 firmware_mgmt NOTICE: task_instance.lua(325): sys_id=1, fw_type=Bios, filename=/dev/shm/upgrade/2866844768/Firmware1
2026-04-21 10:54:05.967933 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.970133 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.978347 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.980173 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:05.986611 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:05.988703 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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 f
2026-04-21 10:54:05.990263 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:05.991705 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:05.993123 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:05.996055 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:05.997434 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:05.998190 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:06.061215 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:06.092108 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.l
2026-04-21 10:54:06.093329 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:06.094596 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:25
2026-04-21 10:54:06.096140 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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_
2026-04-21 10:54:06.097476 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:06.098846 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:06.102336 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:06.106776 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:06.108409 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:06.575690 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:06.578759 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:07.064105 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:07.122513 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:07.124599 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:07.127614 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:07.129510 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:07.590074 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:07.591779 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:08.060183 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:08.602421 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:08.604221 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:09.058149 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:09.571658 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:09.573232 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:09.603484 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:09.605373 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:09.780913 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:09.782665 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:09.869175 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:09.871634 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:09.875271 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:09.877407 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:10.063226 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:10.116594 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:10.118382 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:10.604325 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:10.606121 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:11.060790 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:11.618651 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:11.620586 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:12.055805 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:12.058415 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:12.060181 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:12.627395 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:12.629450 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:12.866924 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:12.868800 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:12.872845 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:12.875301 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:13.060968 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:13.637747 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:13.639560 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:14.063263 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:14.651493 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:14.653823 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:15.055771 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:15.643740 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:15.645526 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:15.864743 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:15.866719 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:15.870667 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:15.872528 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:16.058981 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:16.649446 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:16.651314 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:17.062441 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:17.643673 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:17.645593 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:18.056024 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:18.659380 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:18.661190 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:18.862950 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:18.864837 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:18.868657 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:18.871094 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:19.058793 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:19.667619 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:19.669359 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:20.063938 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:20.684788 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:20.686622 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:21.058076 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:21.694595 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:21.696491 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:21.895553 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:21.897400 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:21.900901 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:21.902726 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:22.062596 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:22.697812 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:22.699465 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:23.065460 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:23.697823 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:23.699508 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:24.061206 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:24.694739 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:24.696653 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:24.900560 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:24.902428 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:24.907178 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:24.909077 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:25.063618 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:25.713259 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:25.715002 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:26.056239 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:26.722158 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:26.724585 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:27.063431 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:27.714212 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:27.716586 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:27.863697 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:27.865624 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:27.868752 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:27.870651 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:28.060295 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:28.732556 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:28.734299 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:29.064976 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:29.735908 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:29.737850 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:30.061278 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:30.741889 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:30.745795 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:30.863377 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:30.865747 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:30.869375 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:30.871777 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:31.058402 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:31.747832 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:31.750111 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:32.061005 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:32.747164 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:32.749517 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:33.065490 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:33.759360 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:33.761621 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:33.871888 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:33.874108 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:33.877968 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:33.880236 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:34.062211 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:34.768547 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:34.770532 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:35.056875 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:35.772026 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:35.774079 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:36.059493 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:36.763662 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:36.765933 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:37.005135 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:37.007859 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:37.012415 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:37.014895 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:37.062849 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:37.770982 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:37.772959 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:38.056933 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:38.767115 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:38.769357 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:39.059339 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:39.776522 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:39.778600 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:39.901342 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:39.903615 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:39.907205 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:39.909500 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:40.059349 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:40.785763 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:40.787708 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:41.056537 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:41.788380 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:41.790532 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:42.061770 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:42.798154 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:42.800215 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:42.863750 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:42.866309 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:42.869543 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:42.871718 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:43.057949 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:43.808090 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:43.809973 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:44.060786 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:44.811564 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:44.813599 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:45.064248 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:45.815323 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:45.817361 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:45.860492 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:45.862628 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:45.866246 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:45.868405 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:46.059122 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:46.813290 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:46.815306 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:47.062865 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:47.821823 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:47.823859 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:48.060120 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:48.830380 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:48.832995 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:48.884737 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:48.887129 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:48.892447 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:48.894553 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:49.064920 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:49.837420 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:49.839383 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:50.057784 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:50.852481 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:50.855901 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:50.930419 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:50.932426 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:50.935748 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:50.937776 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:50.942816 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:50.944191 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: PROCESS -> COMMON_FINISH, 95
2026-04-21 10:54:50.946226 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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 f
2026-04-21 10:54:50.948060 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b0dfd860]
2026-04-21 10:54:50.949902 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:50.951387 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:50.954042 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:50.957749 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:50.958588 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b0dfd860] exit
2026-04-21 10:54:51.044273 firmware_mgmt NOTICE: task_instance.lua(266): wait_msg_result stage=COMMON_FINISH, timeout=7200S, loop=449
2026-04-21 10:54:51.045170 firmware_mgmt NOTICE: action.lua(96): public finish action start
2026-04-21 10:54:51.131557 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:51.134302 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:51.137107 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:51.866705 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:51.868964 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:52.097382 firmware_mgmt NOTICE: action.lua(102): public finish action end
2026-04-21 10:54:52.098303 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: COMMON_FINISH -> DIFF_FINISH, 95
2026-04-21 10:54:52.136615 firmware_mgmt DEBUG: tasks_scheduling.lua(129): queue num: cached:0, process:1
2026-04-21 10:54:52.199333 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:52.218558 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:52.220125 firmware_mgmt NOTICE: info_mgmt.lua(240): info_key(1_Bios_2866844768) upgrade set_stage: DIFF_FINISH -> CLEAR, 95
2026-04-21 10:54:52.300540 firmware_mgmt NOTICE: task_instance.lua(266): wait_msg_result stage=CLEAR, timeout=600S, loop=0
2026-04-21 10:54:52.302017 firmware_mgmt NOTICE: task_instance.lua(577): Upgrade 1_Bios_2866844768 completely, pre_version=KL4.41.101.260327.R
2026-04-21 10:54:52.302808 firmware_mgmt NOTICE: task_instance.lua(583): firmware(info key:1_Bios_2866844768) do upgrade ret:0, pre_version:KL4.41.101.260327.R
2026-04-21 10:54:52.360016 firmware_mgmt NOTICE: task_mgmt.lua(418): Update task[Id: 2866844768, StartTime: 2026-04-21T10:54:02+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'
2026-04-21 10:54:52.361682 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
2026-04-21 10:54:52.365028 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], interface[bmc.kepler.TaskService.Task], name[MessageId], value["FirmwareUpgradeComponent"]->["FirmwareUpgradeComplete"], 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'
2026-04-21 10:54:52.366959 firmware_mgmt DEBUG: app_preloader.lua(95): create co[thread: 0x2f34b2158460]
2026-04-21 10:54:52.368776 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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.lu
2026-04-21 10:54:52.370396 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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:
2026-04-21 10:54:52.374263 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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
2026-04-21 10:54:52.375495 firmware_mgmt DEBUG: object.lua(83): set property traceback: sender[bmc.kepler.firmware_mgmt], path[/bmc/kepler/UpdateService/TaskService/Tasks/2866844768], 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: i
2026-04-21 10:54:52.376236 firmware_mgmt DEBUG: app_preloader.lua(58): co[thread: 0x2f34b2158460] exit
6

目前看是写入flash内容和读取写入区域的内容不符，应该还是硬件问题，可以手动加载驱动写flash和读flash，看看内容是不是一致，
./bmcdfx coreMsg secfw set biosMuxStatus 1
rmmod sfc0_drv
insmod /lib/modules/hibmc/sfc0_drv.ko g_clk_mhz=15
./mtd_debug write /dev/mtd0 0 33554432 /data/bios.bin
./mtd_debug read /dev/mtd0 0 33554432 /data/bios.bin
./bmcdfx coreMsg secfw set biosMuxStatus 0

7

具体工具可以联系厂商

8

这俩工具需要怎么获取，目前这边没有

9

建议联系厂商对应接口人

10

建议联系对应的项目支持，openUBMC社区无法提供相关工具

11

硬件提供了一个思路，软件能否在哪里修改SPI总线的速度，这个可以调整吗？

12

image
image545×230 9.62 KB