项目

一般

简介

错误 #538

Rel_2.1.5之后， 出现基站启动后挂死，超时原因txconfig带的slot号和物理层当前的不一致

由 吕 国荣 在 将近 4 年 之前添加. 更新于 大约 2 年 之前.

状态:
反馈
优先级:
低
指派给:
吕 国荣
类别:
-
开始日期:
2021-05-12
计划完成日期:
2021-10-31
% 完成:

0%

预期时间:
问题归属:
系统
发现问题版本:
Rel_2.1.6
目标解决问题版本:
Rel_2.1.9P
FPGA板卡类型:
690T+PRU
CPU类型:

历史记录

#1

由 吕 国荣 更新于 将近 4 年 之前

  • 状态 从 新建 变更为 进行中
[05-12 11:37:51.941][DEBUG]Func:phy_bbupool_update_multi_cell_status, nSfIdx[3], nCellNum[1]
[05-12 11:37:51.941][DEBUG]PUSH_API_TO_QUEUE:[push:1, pop:0], apiArraySfn[6] numInQueue[1]
[05-12 11:37:51.941][DEBUG]---- 0_DL_L1_CONFIG [phy_gnb_bbupool_task_dl_config] CellIdx[0] Subframe[3] SlotAdvIdx[5] Ctx[1] timediff[508.540]us
[05-12 11:37:51.941][DEBUG]POP_API_FROM_QUEUE:[push:1, pop:1], apiArraySfn[328000] numInQueue[0]
[05-12 11:37:51.941][INFO ]nr5g_gnb_mac2phy_api_proc_dl_config_req, Tx[0,6] nGroup[0] nPDU[0] diff[2943542099.968]us
[05-12 11:37:51.941][DEBUG]PHYStateTx: nNumPdsch[0] nNumPdcch[0] nNumPbch[0] nCSICount[0] nPDU[0]
[05-12 11:37:51.941][ *ERROR* ]phy_gnb_bbupool_task_dl_config, CellIdx[0] Subframe[3] SlotAdvIdx[5] Ctx[1] TxFrameNumber[0] SlotNum[6] CurrSlotNum[5]// txconfig中填写的值为6，本地为5
[05-12 11:37:51.941][DEBUG]Func:phy_gnb_bbupool_task_ul_config, CellId[0] Slot[3] SlotAdvIdx[3] Ctx[3] nListRunning[0]
[05-12 11:37:51.941][ *ERROR* ]Func:phy_gnb_bbupool_task_ul_config, CellIdx[0] Subframe[3] SlotAdvIdx[3] iCtx[3] RxFrameNum[0] SlotNum[4] CurrSlotNum[3] gMySfn[7]//ulconfig中填写的为4，本地为3
[05-12 11:37:51.941][FATAL]phy_bbupool_reset_cell_state, Reset pBbu->nCurrentSfIdx--->>>[-1]
[05-12 11:37:51.941][ERROR]An ambiguous subframe index 4 is received at CurrentSfIdx[-1], caller[1], TimeDiff[4]
[05-12 11:37:51.941][FATAL]gnb_fh_thread, TimeLastUs[629] TimeDiff[1] Realslot[0] TimeOut_Cnt[1]
[05-12 11:37:51.941][ERROR]Update SfIdx by CallerFlag[0]: CurrentSfIdx[-1] --> SfIdx[0]

[05-12 11:37:51.941][DEBUG]Func:phy_bbupool_update_multi_cell_status, nSfIdx[0], nCellNum[1]
[05-12 11:37:51.942][INFO ]BBU Pooling: enter multicell Activate!
[05-12 11:37:51.942][INFO ]BBU Pooling: active result: Q_id = 0,currenSf = 20480, curCellNum = 1, activesfn = 4, CellNumInActSfn = 2
[05-12 11:37:51.942][INFO ]BBU Pooling: multiCell Activate sucessfully!
[05-12 11:37:51.942][ERROR]An ambiguous subframe index 5 is received at CurrentSfIdx[0], caller[1], TimeDiff[4]
[05-12 11:37:51.942][FATAL]gnb_fh_thread, TimeLastUs[628] TimeDiff[1] Realslot[1] TimeOut_Cnt[2]
[05-12 11:37:51.942][ERROR]Update SfIdx by CallerFlag[0]: CurrentSfIdx[0] --> SfIdx[1]
#2

由 吕 国荣 更新于 将近 4 年 之前

增加log打印，看到当前发送到du的tti是3，提前2个slot调度，slotadv是5，但是du回来的dl config是消息中slot是6。导致异常返回

[05-12 18:15:15.155][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[3], CellNum[1]
[05-12 18:15:15.155][DEBUG][PHY-->DU] MSG_TYPE_PHY_SLOT_IND: CellNum[1], SlotIdx[3], TTI[0,3].
[05-12 18:15:15.155][DEBUG]PUSH_API_TO_QUEUE:[push:1, pop:0], apiArraySfn[6] numInQueue[1]
[05-12 18:15:15.155][DEBUG]---- 0_DL_L1_CONFIG [phy_gnb_bbupool_task_dl_config] CellIdx[0] Subframe[3] SlotAdvIdx[5] Ctx[1] timediff[509.420]us
[05-12 18:15:15.155][DEBUG]POP_API_FROM_QUEUE:[push:1, pop:1], apiArraySfn[328000] numInQueue[0]
[05-12 18:15:15.155][INFO ]DU2PHY_Api_Proc_DL_Config_Req, Tx[0,6] nGroup[0] nPDU[0] diff[14526085857.280]us
[05-12 18:15:15.155][DEBUG]PHYStateTx: nNumPdsch[0] nNumPdcch[0] nNumPbch[0] nCSICount[0] nPDU[0]
[05-12 18:15:15.155][ERROR]phy_gnb_bbupool_task_dl_config, CellIdx[0] Subframe[3] SlotAdvIdx[5] Ctx[1] TxFrameNumber[0] SlotNum[6] CurrSlotNum[5]
[05-12 18:15:15.155][DEBUG]Func:phy_gnb_bbupool_task_ul_config, CellId[0] Slot[3] SlotAdvIdx[3] Ctx[3] nListRunning[0]
[05-12 18:15:15.155][ERROR]Func:phy_gnb_bbupool_task_ul_config, CellIdx[0] Subframe[3] SlotAdvIdx[3] iCtx[3] RxFrameNum[0] S

#3

由 guo hanlin 更新于 将近 4 年 之前

【YZS_NRP_V2.0.50】SRS调试中出现两次物理层启动即挂死，其中：
"Func:DU2PHY_Api_Proc_Rx, iCtx1, phyInstance0, pRxConfig= NULL" 只出现了两次，正常为三次

[07-19 10:49:27.647][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[20477], CellNum[1]
[07-19 10:49:27.647][INFO ]BBU Pooling: enter multicell Activate!
[07-19 10:49:27.647][INFO ]BBU Pooling: active result: Q_id = 0,currenSf = 20477, curCellNum = 0, activesfn = 1, CellNumInActSfn = 1
[07-19 10:49:27.647][INFO ]BBU Pooling: multiCell Activate sucessfully!
[07-19 10:49:27.647][INFO ]BBU Pooling Info: bbupool rt thread start on CoreIdx 4 coreId 10 at 14304753277362 at sf=20477 with queue 0 successfully
[07-19 10:49:27.647][INFO ]BBU Pooling Info: bbupool rt thread start on CoreIdx 2 coreId 7 at 14304753277638 at sf=20477 with queue 0 successfully
[07-19 10:49:27.647][INFO ]BBU Pooling Info: bbupool rt thread start on CoreIdx 0 coreId 5 at 14304753292052 at sf=20477 with queue 0 successfully
[07-19 10:49:27.647][INFO ]BBU Pooling Info: bbupool rt thread start on CoreIdx 1 coreId 6 at 14304753307124 at sf=20477 with queue 0 successfully
[07-19 10:49:27.647][INFO ]BBU Pooling Info: bbupool rt thread start on CoreIdx 3 coreId 9 at 14304753322526 at sf=20477 with queue 0 successfully
[07-19 10:49:27.648][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[20478], CellNum[1]
[07-19 10:49:27.648][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[20479], CellNum[1]
[07-19 10:49:27.649][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[0], CellNum[1]
[07-19 10:49:27.649][DEBUG]FH_PRACH_RX, CellIdx[0] slotIdx[20479] eCellActive[10] bbuRunningFlag[1] gPhyState[1] PRACH_ArriveTimeDiff[10002.575]us
[07-19 10:49:27.649][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[1], CellNum[1]
[07-19 10:49:27.649][INFO ]phy_bbupool_rx_handler: PhyId[0] nSfIdx[1] frame,slot[0,1] gNumSlotPerSfn[20]

[07-19 10:49:27.649][DEBUG][PHY-->DU] MSG_TYPE_PHY_SLOT_IND: CellNum[1], SlotIdx[1], TTI[0,1].
[07-19 10:49:27.649][WARNG]DU2PHY_Api_Proc_Tx, pstDU2PhyApi->pTxConfig=null, rc = FAILURE 
[07-19 10:49:27.649][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[5] CellIdx[0] SlotIdx[1] taskType[0] prevSched[TaskSched(0)-1]
[07-19 10:49:27.649][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[5] CellIdx[0] SlotIdx[1] taskType[1] prevSched[TaskSched(0)-1]
[07-19 10:49:27.649][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[5] CellIdx[0] SlotIdx[1] taskType[2] prevSched[TaskSched(0)-1]
[07-19 10:49:27.649][DEBUG]prach_debug isClear[0] iCtx[1] SlotIdx[1] taskType[3] TaskSched[0]
[07-19 10:49:27.649][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[5] CellIdx[0] SlotIdx[1] taskType[3] prevSched[TaskSched(0)-1]
[07-19 10:49:27.649][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[5] CellIdx[0] SlotIdx[1] taskType[4] prevSched[TaskSched(0)-1]
[07-19 10:49:27.649][DEBUG]phy_fpga_dl_set_remap_buffer, SlotIdx[1] SlotAdvIdx[3] bufIdx[3] oneSymDataSize[13104], PktLen[26240]
[07-19 10:49:27.649][DEBUG]Func:phy_gnb_bbupool_task_ul_config, CellId[0] Slot[1] SlotAdvIdx[1] Ctx[1] nListRunning[0]
[07-19 10:49:27.649][ERROR]"Func:DU2PHY_Api_Proc_Rx, iCtx[1], phyInstance[0], pRxConfig= NULL" 
[07-19 10:49:27.649][DEBUG]phy_ul_pusch_symbol_buffer_pre_alloc_func, RX[0, 0], PUSCHGrantNum[0], CompressPUSCHProcess[0]
[07-19 10:49:27.649][DEBUG][phy_dl_x86_encode_task_func]: CellIdx[0] SlotIdx[1] SlotAdvIdx[3] Ctx[3] FEC_DealTime[4.500]us
[07-19 10:49:27.649][DEBUG]Func:phy_gnb_bbupool_post_task_ul_pusch_de_scramble, CellIdx[0] Slot[1] SlotAdvIdx[1] iCtx[1]
[07-19 10:49:27.649][DEBUG]Func:phy_gnb_bbupool_post_task_ul_pusch_decoder, CellIdx[0] Slot[1] SlotAdvIdx[1] iCtx[1]
[07-19 10:49:27.649][DEBUG]Func:Reset_ul_buf, CellIdx[0] slot[1] SlotAdvIdx[1] iCtx[1] PhyState[1] bufIdx[4] RBNum[273] oneSymDataSize[13104]
[07-19 10:49:27.649][DEBUG]phy_gnb_bbupool_ul_set_list: prach_debug isClear[1] iCtx[1] SlotIdx[1] taskType[3] TaskSched[0]
[07-19 10:49:27.650][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[2], CellNum[1]
[07-19 10:49:27.650][DEBUG][PHY-->DU] MSG_TYPE_PHY_SLOT_IND: CellNum[1], SlotIdx[2], TTI[0,2].
[07-19 10:49:27.650][WARNG]DU2PHY_Api_Proc_Tx, pstDU2PhyApi->pTxConfig=null, rc = FAILURE 
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[6] CellIdx[0] SlotIdx[2] taskType[0] prevSched[TaskSched(0)-1]
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[6] CellIdx[0] SlotIdx[2] taskType[1] prevSched[TaskSched(0)-1]
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[6] CellIdx[0] SlotIdx[2] taskType[2] prevSched[TaskSched(0)-1]
[07-19 10:49:27.650][DEBUG]prach_debug isClear[0] iCtx[2] SlotIdx[2] taskType[3] TaskSched[0]
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[6] CellIdx[0] SlotIdx[2] taskType[3] prevSched[TaskSched(0)-1]
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_ul_set_list: Already Scheduled gMySfn[6] CellIdx[0] SlotIdx[2] taskType[4] prevSched[TaskSched(0)-1]
[07-19 10:49:27.650][DEBUG]phy_fpga_dl_set_remap_buffer, SlotIdx[2] SlotAdvIdx[4] bufIdx[4] oneSymDataSize[13104], PktLen[26240]
[07-19 10:49:27.650][DEBUG]Func:phy_gnb_bbupool_task_ul_config, CellId[0] Slot[2] SlotAdvIdx[2] Ctx[2] nListRunning[0]
[07-19 10:49:27.650][ERROR]"Func:DU2PHY_Api_Proc_Rx, iCtx[2], phyInstance[0], pRxConfig= NULL" 
[07-19 10:49:27.650][DEBUG]phy_ul_pusch_symbol_buffer_pre_alloc_func, RX[0, 0], PUSCHGrantNum[0], CompressPUSCHProcess[0]
[07-19 10:49:27.650][DEBUG][phy_dl_x86_encode_task_func]: CellIdx[0] SlotIdx[2] SlotAdvIdx[4] Ctx[0] FEC_DealTime[4.500]us
[07-19 10:49:27.650][DEBUG]Func:phy_gnb_bbupool_post_task_ul_pusch_de_scramble, CellIdx[0] Slot[2] SlotAdvIdx[2] iCtx[2]
[07-19 10:49:27.650][DEBUG]Func:phy_gnb_bbupool_post_task_ul_pusch_decoder, CellIdx[0] Slot[2] SlotAdvIdx[2] iCtx[2]
[07-19 10:49:27.650][DEBUG]Func:Reset_ul_buf, CellIdx[0] slot[2] SlotAdvIdx[2] iCtx[2] PhyState[1] bufIdx[5] RBNum[273] oneSymDataSize[13104]
[07-19 10:49:27.650][DEBUG]phy_gnb_bbupool_ul_set_list: prach_debug isClear[1] iCtx[2] SlotIdx[2] taskType[3] TaskSched[0]
[07-19 10:49:27.650][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[3], CellNum[1]
[07-19 10:49:27.650][DEBUG][PHY-->DU] MSG_TYPE_PHY_SLOT_IND: CellNum[1], SlotIdx[3], TTI[0,3].
[07-19 10:49:27.650][DEBUG]PUSH_API_TO_QUEUE:[push:1, pop:0], apiArraySfn[6] numInQueue[1]
[07-19 10:49:27.650][DEBUG]POP_API_FROM_QUEUE:[push:1, pop:1], apiArraySfn[328000] numInQueue[0]
[07-19 10:49:27.650][DEBUG]PHYStateTx: nNumPdsch[0] nNumPdcch[0] nNumPbch[0] nCSICount[0] nPDU[0]
[07-19 10:49:27.650][ERROR]phy_gnb_bbupool_task_dl_config, CellIdx[0] Subframe[3] SlotAdvIdx[5] Ctx[1] TxFrameNumber[0]' SlotNum[6] CurrSlotNum[5]'
[07-19 10:49:27.650][DEBUG]Func:phy_gnb_bbupool_task_ul_config, CellId[0] Slot[3] SlotAdvIdx[3] Ctx[3] nListRunning[0]
[07-19 10:49:27.650][ERROR]Func:phy_gnb_bbupool_task_ul_config, CellIdx[0] Subframe[3] SlotAdvIdx[3] iCtx[3] RxFrameNum[0] SlotNum[4] CurrSlotNum[3] gMySfn[7]
[07-19 10:49:27.650][FATAL]phy_bbupool_reset_cell_state, Reset pBbu->nCurrentSfIdx--->>>[-1]
[07-19 10:49:27.651][ERROR]An ambiguous subframe index 4 is received at CurrentSfIdx[-1], caller[1], TimeDiff[4]
[07-19 10:49:27.651][FATAL]gnb_fh_thread, TimeLastUs[629] TimeDiff[1] Realslot[0] TimeOut_Cnt[1]
[07-19 10:49:27.651][ERROR]Update SfIdx by CallerFlag[0]: CurrentSfIdx[-1] --> SfIdx[0]

[07-19 10:49:27.651][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[0], CellNum[1]
[07-19 10:49:27.651][INFO ]BBU Pooling: enter multicell Activate!
[07-19 10:49:27.651][INFO ]BBU Pooling: active result: Q_id = 0,currenSf = 20480, curCellNum = 1, activesfn = 4, CellNumInActSfn = 2
[07-19 10:49:27.651][INFO ]BBU Pooling: multiCell Activate sucessfully!
[07-19 10:49:27.651][ERROR]An ambiguous subframe index 5 is received at CurrentSfIdx[0], caller[1], TimeDiff[4]
[07-19 10:49:27.651][FATAL]gnb_fh_thread, TimeLastUs[626] TimeDiff[1] Realslot[1] TimeOut_Cnt[2]
[07-19 10:49:27.651][ERROR]Update SfIdx by CallerFlag[0]: CurrentSfIdx[0] --> SfIdx[1]

[07-19 10:49:27.651][DEBUG]Func:phy_bbupool_update_multi_cell_status, SfIdx[1], CellNum[1]
[07-19 10:49:27.652][ERROR]An ambiguous subframe index 6 is received at CurrentSfIdx[1], caller[1], TimeDiff[4]

#4

由 吕 国荣 更新于 将近 4 年 之前

  • 计划完成日期 从 2021-05-14 变更为 2021-08-01
  • 优先级 从 普通 变更为 高
#5

由 吕 国荣 更新于 超过 3 年 之前

  • 项目 从 FP 变更为 2.0基站产品化测试
  • 主题 从 Rel_2.1.5 出现基站启动后挂死，超时原因txconfig带的slot号和物理层当前的不一致 变更为 Rel_2.1.5之后， 出现基站启动后挂死，超时原因txconfig带的slot号和物理层当前的不一致
  • 类别 已删除 (PHY)
  • 目标版本 已删除 (α版本)
  • 发现问题版本 被设置为 Rel_2.1.6
  • 目标解决问题版本 被设置为 Rel_2.1.9P
  • FPGA板卡类型 被设置为 690T+PRU
  • 问题归属 系统 已添加

2.1.8P测试中仍然出现该问题。

#6

由 吕 国荣 更新于 大约 3 年 之前

再去掉 bbupool main thread线程后，该问题复现率很高。需要确认下，该线程和wls的线程关系。

#7

由 吕 国荣 更新于 将近 3 年 之前

在2.1.10P pre3中的测试过程中出现过1次。

#8

由 高 峰 更新于 超过 2 年 之前

  • 计划完成日期 从 2021-08-01 变更为 2021-10-31
#9

由 吕 国荣 更新于 大约 2 年 之前

  • 状态 从 进行中 变更为 反馈
  • 优先级 从 高 变更为 低

问题基本不在复现！~

导出 Atom PDF