OS下电再上电后系统从状态Off到ON的变化时长实测为1分钟,预期10秒,不符合预期

问题描述

OS下电再上电后系统从状态Off到ON的变化时长实测为1分钟,预期10秒,不符合预期

分析结论

1、怀疑是spi_flash.lua(315): [spi]check_device_ready: ready fail 这个地方导致的

2、原代码中使用的是spi_def.SPIKODRV

spi_def.SPIKODRV = ‘/lib/modules/ko/sfc0_drv.ko’

我们的项目代码中新增了spi_def.SPIKODRV_SFC1 = ‘/lib/modules/ko/sfc1_drv.ko’

所有使用spi_def.SPIKODRV的地方都替换为了spi_def.SPIKODRV_SFC1

3、是不是闭源代码中使用了spi_def.SPIKODRV导致的?

4、如果不是的3的话,帮忙看下spi_flash.lua(315): [spi]check_device_ready: ready fail 这个地方失败的原因

相关的日志片段:

2026-04-14 08:31:48.476827 bios NOTICE: alarm_manager.lua(162): event_list is nil, no need recover, system id: 1
2026-04-14 08:31:48.477399 bios NOTICE: system_info_object.lua(117): system info: obj type: 1, need clear
2026-04-14 08:31:48.477786 bios NOTICE: system_info_object.lua(117): system info: obj type: 1, need clear
2026-04-14 08:31:48.487142 bios NOTICE: signal.lua(447): [bios]multihost is false
2026-04-14 08:31:48.488115 bios NOTICE: pfr_service.lua(105): [PfrService]PfrService: system nil try unlock fructl forever lock.
2026-04-14 08:31:48.987647 bios NOTICE: pfr_service.lua(120): [PfrService]PfrService: system 1 unlock fructl forever lock success.
2026-04-14 08:31:48.988093 bios NOTICE: upgrade_service.lua(959): [bios]clear system 1 slave upgrade flag
2026-04-14 08:31:48.988486 bios NOTICE: reset_lock.lua(107): host 1 post finish or power off
2026-04-14 08:31:55.640004 bios NOTICE: bios_service.lua(216): [bios] system 1 bios receive before power on UpgradeSignal.
2026-04-14 08:31:55.640560 bios NOTICE: pfr_service.lua(176): [PfrService]PfrService: system 1 start lock fructl.
2026-04-14 08:31:55.640912 bios ERROR: power_lock.lua(111): [bios]lock_until_success: system 1 lock start.
2026-04-14 08:31:55.643093 bios NOTICE: signal.lua(522): [bios] bios receive before power on UpgradeSignal.
2026-04-14 08:31:55.643448 fructrl NOTICE: fructrl_obj_mgnt.lua(288): [System:1]set poweron lock, pwronlocked=true, timeout=3000, appname=bios, reason=VerifyFlash
2026-04-14 08:31:55.644209 fructrl NOTICE: pwr_lock.lua(60): [System:nil][bios]Add power on lock to lock_table successfully.
2026-04-14 08:31:55.644773 bios NOTICE: signal.lua(447): [bios]multihost is false
2026-04-14 08:31:55.645311 bios NOTICE: alarm_manager.lua(162): event_list is nil, no need recover, system id: nil
2026-04-14 08:31:55.662810 bios NOTICE: pfr_service.lua(178): [PfrService]PfrService: system 1 lock fructl success.
2026-04-14 08:31:55.663552 bios NOTICE: pfr_service.lua(146): [PfrService]PfrService: system 1 wait power off state.
2026-04-14 08:31:55.664806 bios NOTICE: pfr_service.lua(152): [PfrService]PfrService: system 1 start verify.
2026-04-14 08:31:55.665266 bios NOTICE: gold_package.lua(303): [GoldPackage]GoldPackage:system 1 start verify 1 times.
2026-04-14 08:31:55.665673 bios NOTICE: flash.lua(55): load chipv1 spikodrv
2026-04-14 08:31:55.671430 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:10.872486 bios ERROR: spi_flash.lua(315): [spi]check_device_ready: ready fail
2026-04-14 08:32:10.874081 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:10.874956 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:11.396412 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:11.397284 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:11.913953 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:11.914808 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:12.431020 bios ERROR: flash.lua(133): [bios]switch to os fail
2026-04-14 08:32:12.934737 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:28.009902 bios ERROR: spi_flash.lua(315): [spi]check_device_ready: ready fail
2026-04-14 08:32:28.011400 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:28.012408 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:28.529413 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:28.530294 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:29.058043 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:29.059149 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:29.576902 bios ERROR: flash.lua(133): [bios]switch to os fail
2026-04-14 08:32:30.078003 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:45.168806 bios ERROR: spi_flash.lua(315): [spi]check_device_ready: ready fail
2026-04-14 08:32:45.170782 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:45.171870 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:45.689044 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:45.690254 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:46.217634 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:46.219154 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:46.732373 bios ERROR: flash.lua(133): [bios]switch to os fail
2026-04-14 08:32:47.229021 bios ERROR: flash.lua(145): [bios]switch to bmc fail
2026-04-14 08:32:47.231051 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:47.232334 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:47.757004 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:47.758060 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:48.275272 bios NOTICE: scm3.lua(92): Verify BIOS upgrade flag ok
2026-04-14 08:32:48.276294 bios NOTICE: scm3.lua(104): Set BIOS upgrade flag ok
2026-04-14 08:32:48.792924 bios ERROR: flash.lua(133): [bios]switch to os fail
2026-04-14 08:32:48.793839 bios NOTICE: flash.lua(416): [bios]verify flash success
2026-04-14 08:32:48.794786 bios NOTICE: gold_package.lua(232): system 1 secure_boot_info:
2026-04-14 08:32:48.795483 bios NOTICE: gold_package.lua(77): [bios]secure boot success.
2026-04-14 08:32:48.805257 bios ERROR: gold_package.lua(295): system StringValueTooShort: The string ‘’ was under the minimum required length 64. set secure boot info failed, err: 1
2026-04-14 08:32:48.805733 bios NOTICE: gold_package.lua(309): [GoldPackage]GoldPackage:system 1 verify success
2026-04-14 08:32:48.806060 bios NOTICE: pfr_service.lua(169): [PfrService]PfrService: system 1 verify and recover success, power unlock.
2026-04-14 08:32:48.810415 fructrl NOTICE: fructrl_obj_mgnt.lua(288): [System:1]set poweron lock, pwronlocked=false, timeout=3000, appname=bios, reason=VerifyFlash
2026-04-14 08:32:48.811291 fructrl NOTICE: pwr_lock.lua(84): [System:nil]Update power on lock item successfully, appname=(bios), reason=(VerifyFlash), locked=(false), timeout=(3000)
2026-04-14 08:32:49.670903 fructrl NOTICE: pwr_lock.lua(156): [System:nil]Delete power on lock item, appname=(bios), reason=(VerifyFlash)
2026-04-14 08:32:50.776689 bios NOTICE: signal.lua(75): power state changed set_option_flag = 0, set_effective_flag = 0

答案内容由AI生成,仅供参考:

总结与结论

分析项 结论
:red_question_mark: 是否因替换SPIKODRVSPIKODRV_SFC1导致? 有可能。若闭源模块未适配,则可能导致驱动加载异常,建议实测对比
:red_question_mark: check_device_ready: ready fail 是否为主因? 是核心直接原因,表明SPI Flash未响应
:puzzle_piece: 根本原因最可能是什么? SPI通信异常,特别是:
① 时钟速率过高(尤其走线长)
② BMC未真正获得SPI控制权(CS/CLK无信号)
:wrench: 推荐优先尝试的解决方式 降低SPI速率至10MHz并抓波形验证信号完整性
点击此处查看详细分析解答

关于OS下电再上电后系统从Off到ON变化时长过长的分析

问题描述

系统在执行下电再上电操作后,从状态Off切换到ON的实际耗时为1分钟,而预期时间为10秒,存在严重延迟,不符合性能预期。

关键错误日志分析

2025-12-20 06:38:06.614705 bios ERROR: spi_flash.lua(315): [spi]check_device_ready: ready fail

该错误日志表明在BIOS启动初始化过程中,SPI Flash设备未能被正确识别或准备就绪,导致check_device_ready检查失败。


深度分析与定位

一、关于SPI驱动替换的影响分析

您提到项目中将默认SPI驱动:

spi_def.SPIKODRV = '/lib/modules/ko/sfc0_drv.ko'

替换为:

spi_def.SPIKODRV_SFC1 = '/lib/modules/ko/sfc1_drv.ko'

并且在代码中统一使用了SPIKODRV_SFC1

结论:

  • 驱动切换本身不会直接导致延迟问题,前提是sfc1_drv.ko驱动已正确适配硬件且功能完整。
  • 但若闭源模块(如UpgradeExecutorbios等核心组件)内部仍硬编码依赖于spi_def.SPIKODRV(即sfc0_drv.ko),则可能导致:
    • 部分模块加载旧驱动失败
    • 或驱动初始化异常
    • 进而导致SPI通信超时或重试

:warning: 存在风险点:目前已知 upgrade_executor.lua 会调用 spi_flash.lua 进行设备就绪检查,而此过程依赖底层驱动。若闭源部分未适配新的SPIKODRV_SFC1定义,则可能因驱动不匹配导致通信不稳定。

建议核实以下内容:

  • 闭源模块是否支持自定义SPI驱动路径?
  • sfc1_drv.ko驱动是否经过充分验证?其SPI速率、时序等参数是否与硬件匹配?

二、“check_device_ready: ready fail” 的根本原因分析

该错误发生在文件 spi_flash.lua 的第315行(或316行,见文档日志),其本质是系统无法确认SPI Flash设备已准备好进行读写操作。

核心流程:

  1. BIOS升级/启动过程中,需通过SPI接口访问Flash芯片
  2. 系统调用sfc_spi_general_wait_ready函数等待Flash就绪
  3. 若在规定时间内未收到“就绪”响应,则触发超时错误

可能原因:

原因 证据支持
1. 硬件SPI通信异常(CS/CLK信号异常) 来自用户liutao的反馈显示:BMC虽拉高控制权信号(BMC_SEC_GPIO0),但实际CS和CLK信号未输出,说明BMC未能真正获得SPI总线控制权
2. SPI时钟速率过高导致信号失真 用户wangdong在另一案例中指出:硬件走线过长时,若SPI速率设置为25MHz,会导致芯片ID移位、识别失败,最终造成mtd_api.write卡死于Wait SPI Flash Ready Timeout
3. 多驱动冲突或资源竞争 加载sfc1_drv.ko可能与其他内核模块存在资源抢占或CS片选冲突
4. Flash芯片响应延迟 某些SPI Flash在冷启动时需较长唤醒时间,而驱动未做相应延时处理

三、是否有证据表明闭源代码仍使用原始SPIKODRV?

目前知识库中未明确提及闭源组件是否写死使用spi_def.SPIKODRV

但可以从逻辑推断:

  • UpgradeExecutor作为核心升级管理器,依赖SpiFlash模块进行操作
  • spi_flash.luaupgrade_executor.lua调用
  • 若该调用链中的驱动加载路径未开放配置接口,则很可能仍使用默认SPIKODRV

:white_check_mark: 建议验证方法
执行以下命令查看当前加载的驱动:

lsmod | grep sfc
dmesg | grep sfc_core_spi_probe

观察日志中是否出现:

[sfc_core_spi_probe] SpI(cs0) ID: RXID not right!

如果有此类打印,说明驱动未能正确读取Flash ID,极可能是驱动与硬件不匹配或SPI速率过高所致。


排查与解决方案建议

:white_check_mark: 方案1:降级SPI时钟速率测试

适用场景:硬件走线较长或信号完整性较差

依据wangdong在类似问题中验证过,降低SPI速率可解决Wait SPI Flash Ready Timeout问题

操作建议

  • 修改驱动配置,将SPI速率从25MHz降至10~15MHz
  • 重新测试上下电时间
  • 验证dmesg中是否不再出现Wait spi flash ready timeoutRXID not right错误

:white_check_mark: 方案2:检查BMC SPI控制权切换机制

关键点:即使BMC声称已获取控制权(如GPIO拉高),但实际无CLK/CS信号输出,说明切换逻辑失败

排查步骤

  1. 使用逻辑分析仪捕获SPI总线上的CS、CLK、MOSI、MISO信号
  2. 确认在check_device_ready阶段是否有CLK脉冲输出
  3. 检查set_spi_owner逻辑是否完成
  4. 询问硬件团队:是否存在多主设备(如SoC与BMC)争抢SPI总线?是否有物理复用开关未正确配置?

:white_check_mark: 方案3:回退至原始SPI驱动对比测试

目的:排除因sfc1_drv.ko驱动不成熟引发的问题

操作步骤

  1. 暂时恢复使用sfc0_drv.ko驱动
  2. 保持其他代码不变,执行上下电测试
  3. 若耗时恢复至10秒以内 → 说明问题出在sfc1_drv.ko或其配置上

:white_check_mark: 方案4:增加驱动初始化超时与重试机制

改进建议:在spi_flash.lua中增加健壮性处理

-- 示例增强逻辑
local max_retries = 3
for i = 1, max_retries do
    local ready = check_device_ready()
    if ready then break end
    msleep(50) -- 每次失败后等待50ms
end

同时可加入日志记录SPI ID探测过程,便于快速定位Flash识别问题。


总结与结论

分析项 结论
:red_question_mark: 是否因替换SPIKODRVSPIKODRV_SFC1导致? 有可能。若闭源模块未适配,则可能导致驱动加载异常,建议实测对比
:red_question_mark: check_device_ready: ready fail 是否为主因? 是核心直接原因,表明SPI Flash未响应
:puzzle_piece: 根本原因最可能是什么? SPI通信异常,特别是:
① 时钟速率过高(尤其走线长)
② BMC未真正获得SPI控制权(CS/CLK无信号)
:wrench: 推荐优先尝试的解决方式 降低SPI速率至10MHz并抓波形验证信号完整性

建议下一步动作

  1. 抓取dmesg日志,重点查看:
    sfc_core_spi_probe
    sfc_spi_general_wait_ready
    Wait spi flash ready timeout
    
  2. 使用逻辑分析仪观察CS、CLK信号在启动时是否正常输出
  3. 临时回退使用sfc0_drv.ko,验证是否因驱动差异导致
  4. 联系硬件团队确认SPI总线切换机制与信号质量

一旦确认为SPI速率过高导致,可在驱动层调整参数,从根本上解决问题。