mctp request timeout

交流互助区
1

问题描述

OpenUBMC通过MCTP over SMBus通信。MCTP Set EID命令通信正常。但是OEM指令出现 Mctp request timeout。

环境信息

  • 操作系统：

  • 软件版本：OpenUBMC2609

  • 硬件配置：米尔开发板hi3093，网卡与开发板i2c_8直连

期望结果

NC-SI over MCTP的OEM命令能够及时送达ncsi层，驱动去解析。

实际结果

出现Mctp request timeout，报文在mctp层就丢了。

个人分析

% tracemctp start
============= SMBus_OEM capture [SEND] =============
D4 1F 22 21 01 1E 08 C8 02 00 01 00 09 50 00 00
08 00 00 00 00 00 00 00 00 00 00 EE 9E 02 00 00
00 FF FE BF 50 3E
============= SMBus_OEM capture [RECV] =============
D4 1F 2E D5 01 08 1E C0 02 00 01 00 09 D0 00 00
14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 EE
9E 82 00 00 00 00 2D 00 24 00 00 00 00 FF FD BE
F3 81 FF 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00

【app.log日志】
1970-01-01 00:18:56.801700 general_hardware NOTICE: mcu_service.lua(35): start serial task for update mcu version
1970-01-01 00:19:00.802265 devmon ERROR: mctp.cpp(71): [MCTP_DBG] mctp::request ENTRY, name=0103_106/2, data_len=8, timeout=0ms
1970-01-01 00:19:00.802636 devmon ERROR: mctp.cpp(74): [MCTP_DBG] mctp::request TX hex: 00 00 EE 9E 02 00 00 00
1970-01-01 00:19:00.802964 devmon ERROR: mctp.cpp(94): [MCTP_DBG] mctp::request → D-Bus call, dest=bmc.kepler.mctpd, path=/bmc/kepler/Systems/1/Mctp/Endpoint/0103_106/2, iface=bmc.kepler.Systems.Mctp.PCIeEndpoint
1970-01-01 00:19:00.812443 devmon ERROR: chip.cpp(580): [MCTP_DBG] data_access START, chip=Chip_SmbusChip_0103, op=WRITE, addr=0xD4, offset=31, len=36, mask=0x00000000
1970-01-01 00:19:00.812911 devmon ERROR: chip.cpp(582): [MCTP_DBG] data_access in_buffer (36B): 22 21 01 1E 08 C8 02 00 01 00 09 50 00 00 08 00 00 00 00 00 00 00 00 00 00 EE 9E 02 00 00 00 FF FE BF 50 3E
1970-01-01 00:19:00.813509 devmon ERROR: i2c.cpp(289): [MCTP_DBG] bus_i2c::write ENTRY, id=8, addr=0xD4, len=36, delay=200ms, hex=D4 1F 22 21 01 1E 08 C8 02 00 01 00 09 50 00 00 08 00 00 00 00 00 00 00 00 00 00 EE 9E 02 00 00 …
1970-01-01 00:19:01.017714 devmon ERROR: i2c.cpp(294): [MCTP_DBG] bus_i2c::write ← i2c_drv->write ret=0
1970-01-01 00:19:01.018182 devmon ERROR: chip.cpp(611): [MCTP_DBG] data_access END, chip=Chip_SmbusChip_0103, op=WRITE, ret=0, out_len=0
1970-01-01 00:19:01.018637 devmon ERROR: chip.cpp(580): [MCTP_DBG] data_access START, chip=Chip_SmbusChip_0103, op=READ, addr=0xD4, offset=31, len=129, mask=0x00000000
1970-01-01 00:19:01.018969 devmon ERROR: chip.cpp(582): [MCTP_DBG] data_access in_buffer (0B): (empty)
1970-01-01 00:19:01.019301 devmon ERROR: i2c.cpp(260): [MCTP_DBG] bus_i2c::read ENTRY, offset=31, protocol_flag=0, len=129
1970-01-01 00:19:01.019519 devmon ERROR: i2c.cpp(273): [MCTP_DBG] bus_i2c::read → branch: normal_read
1970-01-01 00:19:01.019962 devmon ERROR: i2c.cpp(165): [MCTP_DBG] normal_read ENTRY, id=8, addr=0xD4, offset=31, offsetWidth=1, len=129
1970-01-01 00:19:01.021917 devmon ERROR: i2c.cpp(169): [MCTP_DBG] normal_read → tx hex: D4 1F
1970-01-01 00:19:01.035033 devmon ERROR: i2c.cpp(194): [MCTP_DBG] normal_read ← i2c_drv->read OK, rx len=129, rx hex: 2E D5 01 08 1E C0 02 00 01 00 09 D0 00 00 14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 EE 9E 82 00 00 00 00 2D 00 24 00 00 00 00 FF FD BE F3 81 FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1970-01-01 00:19:01.035671 devmon ERROR: chip.cpp(605): [MCTP_DBG] data_access out_buffer (129B): 2E D5 01 08 1E C0 02 00 01 00 09 D0 00 00 14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 EE 9E 82 00 00 00 00 2D 00 24 00 00 00 00 FF FD BE F3 81 FF 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1970-01-01 00:19:01.036030 devmon ERROR: chip.cpp(611): [MCTP_DBG] data_access END, chip=Chip_SmbusChip_0103, op=READ, ret=0, out_len=129
1970-01-01 00:19:01.047873 hardware DEBUG: smbus_protocol.cpp(95): smbus_protocol: unmatch crc, crc from data: 0, computed crc: 189
1970-01-01 00:19:02.285935 power_mgmt NOTICE: power_mgmt_app.lua(391): [power_mgmt] init OK
1970-01-01 00:19:05.795148 interface NOTICE: libcrypt.c(378): create rsa key success.
1970-01-01 00:19:15.805225 devmon ERROR: mctp.cpp(108): [MCTP_DBG] mctp::request FAILED, name=0103_106/2, exception: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
1970-01-01 00:19:15.805587 devmon ERROR: ne6000_card.cpp(242): Failed to get temperatures from OEM 0x02
1970-01-01 00:19:15.811267 hardware DEBUG: sysv_rwlock_embedded.c(116): [rwlock][wrlock:acquired] semid=0 readers=0 writers=1 waiting_writers=0 write_pending=0
1970-01-01 00:19:15.811496 hardware DEBUG: sysv_rwlock_embedded.c(116): [rwlock][unlock_write:after] semid=0 readers=0 writers=0 waiting_writers=0 write_pending=0
1970-01-01 00:19:15.817879 mctpd DEBUG: mctp_engine.lua(364): [System1]mctp_engine: request timeout, key=30:27136:0:9, timeout_ms=15000
1970-01-01 00:19:15.818700 mctpd DEBUG: errors.lua(62): ep_ncsi.lua:55 > ep_mctp.lua:98 > mctp_engine.lua:427: The Mctp request timeout.

【nic端日志】
[LOG_DBG] Smbus [BMC write] Done, Total len: 38, Data: d4 1f 22 21 01 1e 08 c8 02 00 01 00 09 50 00 00 08 00 00 00 00 00 00 00 00 00 00 ee 9e 02 00 00 00 ff fe bf 50 3e
[LOG_DBG] MCTP [Slave TX] Prepared 51 bytes total (Tx start from pos 3)
[LOG_DBG] Smbus [Slave TX Ready] (0x1F) len: 51, Data: d4 1f d5 2e d5 01 08 1e c0 02 00 01 00 09 d0 00 00 14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ee 9e 82 00 00 00 00 2d 00 24 00 00 00 00 ff fd be f3 81
[LOG_DBG] Smbus [BMC read] Done, Tx bytes: 51, Data: d4 1f d5 2e d5 01 08 1e c0 02 00 01 00 09 d0 00 00 14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ee 9e 82 00 00 00 00 2d 00 24 00 00 00 00 ff fd be f3 81

【网卡端crc计算】
crc计算的时候是在前面补3个字节，地址（d4） 命令字（1F）地址|1（d5）.也就是d4 1f d5 2E D5 01 08 1E C0 02 00 01 00 09 D0 00 00 14 00 00 00 00 00 00 00 00 00 00 00 00 00 00 EE 9E 82 00 00 00 00 2D 00 24 00 00 00 00 FF FD BE F3 81，最后计算的crc；

【报文分析】
D4 1F 2E [3 header]
D5 01 08 1E C0 02 00 01 00 09 D0 00 00 14 00 00
00 00 00 00 00 00 00 00 00 00 00 00 EE 9E 82 00
00 00 00 2D 00 24 00 00 00 00 FF FD BE F3 [46]
81 【第47B crc】

AI分析read报文的格式和crc没有问题，但是"hardware DEBUG: smbus_protocol.cpp(95): smbus_protocol: unmatch crc, crc from data: 0, computed crc: 189" 这个日志看起来又是获取crc的位置不对？AI读取mctp源代码，smbus_protocol.cpp中取 PEC 用了 data.size() 而非 byte_count，是否是因为这个原因？
网卡端只发送了50B，但是i2c.cpp中增加的调试日志和mctp的跟踪日志都看到，rx len是129，这个是否会有影响？

2

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

5. 总结

当前问题的最可能根因是 SMBus 协议层的 CRC 校验失败，导致有效的 MCTP 响应被 BMC 丢弃。建议优先核对 CRC 计算规则，并参考社区已解决的同类 bug。若 CRC 确认无误，再考虑分片或超时参数等其他配置因素。

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

问题分析与定位建议

根据您提供的问题描述、日志及报文分析，结合知识库中的相关信息，对 MCTP request timeout 的成因进行如下分析。

1. 现象确认

  • MCTP Set EID 命令通信正常，说明 MCTP over SMBus 基础链路（I2C-8）以及 MCTP 协议栈的底层收发是通的。
  • OEM 指令（如获取温度）出现 Mctp request timeout，日志显示请求发出后，BMC 侧等待响应超时，最终导致应用层（如 ne6000_card.cpp）报告失败。

2. 关键日志线索

从您提供的 app.log 中，最核心的异常出现在 SMBus 协议层：

smbus_protocol.cpp(95): smbus_protocol: unmatch crc, crc from data: 0, computed crc: 189
  • BMC 在读取网卡回复的 129 字节数据后，执行 SMBus 层 CRC 校验，发现收到的 CRC 字段为 0，而本地计算出的 CRC 为 189，两者不匹配。
  • 该 CRC 校验失败导致 BMC 判定响应无效，丢弃了该数据包，因此 MCTP 层始终未收到有效响应，最终触发请求超时。

3. 根因推断（基于上下文证据）

  • CRC 算法不一致或计算错误：知识库中提到 chain914 曾确认并解决过一个 CRC 算法 bug，表明该领域存在已知的算法实现风险。您的日志显示的 CRC 不匹配，很可能就是 CRC 计算规则（例如计算时的字节范围、初始值、多项式）与网卡侧不一致所致。
  • 响应分片问题（次要可能性）：知识库中提及 NC-SI over MCTP over SMBus 场景下，应答报文超过 MTU 时会按 64 字节分片（当前 OpenUBMC MCTPD 的 MTU 为 128 字节）。您的响应数据长度为 129 字节，恰好超出单包承载能力，若分片处理不完整，也会导致后续数据丢失。但从日志看，BMC 确实读取到了完整的 129 字节（含所有分片），因此分片问题不是直接原因，而 CRC 错误才是最明确的失败点。

4. 直接建议

  1. 核对 CRC 算法实现
    对比 BMC 侧（smbus_protocol.cpp）与网卡侧（日志中“网卡端crc计算”）的 CRC 计算规则，确认：

    • 参与计算的字节范围是否一致（网卡侧在前面补了 3 个字节：地址、命令字、地址|1）；
    • CRC 的初始值、多项式、输出是否使用相同标准。

  2. 参考社区既有修复经验
    知识库中提到 chain914 已解决过 CRC 算法 bug，可检索相关论坛帖子（如“CRC算法bug”相关讨论），获取已验证的修正代码或配置。

  3. 使用诊断工具进一步定位
    您已使用 tracemctp 捕获报文，可以结合 mdbctl、busctl 手动构造 SMBus 读写，直接验证 CRC 校验逻辑（参考文档片段中的“busctl手动发送smbus报文获取响应”方法）。

  4. 排查 SMBus 芯片配置
    日志中的 Chip_SmbusChip_0103 是通信的 SMBus 设备，检查其属性（如地址、地址宽度、偏移宽度）是否与网卡实际行为匹配，避免因配置差异导致读取的数据偏移或长度异常（知识库中提到过“invalid byte count”等错误类型，此处虽不是 byte count 错误，但配置错误可能影响 CRC 计算）。

5. 总结

当前问题的最可能根因是 SMBus 协议层的 CRC 校验失败，导致有效的 MCTP 响应被 BMC 丢弃。建议优先核对 CRC 计算规则，并参考社区已解决的同类 bug。若 CRC 确认无误，再考虑分片或超时参数等其他配置因素。