Aerial Testbed: [SCF.PHY] on_msg: Incorrect msg length

Accelerated Computing Aerial Forum
1

Hi,

When use the setup the Aerial Testbed according to the guide,
the RU can receive the c-plane, but no u-plane, check the FAPI

image
image1910×481 57.8 KB

any sw version unmatched? I installed the sw according to the below guide

git clone --recurse-submodules GitHub - NVIDIA/aerial-cuda-accelerated-ran: An SDK (Software Development Kit) for building commercial-grade, AI-native, 3GPP, and O-RAN compliant 5G/6G gNB software on NVIDIA-accelerated computing platforms. · GitHub ~/aerial-cuda-accelerated-ran
cd ~/aerial-cuda-accelerated-ran/cubb_scripts/install/
sudo apt install make tmux git-lfs && git lfs pull
tmux new-session -s “aerial-cuda-accelerated-ran” -n “installation”
make all && sudo reboot
RU_MAC= OAI_BRANCH=ATB1.1 OAI_REPO=GitHub - duranta-project/openairinterface5g: Duranta - An open, research-grade RAN + UE reference stack · GitHub make all

2

Hi @xuyc1

What type of O-RU are you using? are the C-plane packets on RU side on-time?

Thanks,

3

thanks @jixu

  1. the ORU is sera ORU-NM4400

  2. there is a grandmaster issue, RU can receive the c-plane, but it is “too early”, so please ignore the UL traffic in fronthual

Does the DL throughput only count u-plane?

image
image1804×610 74.1 KB

4

Hi @xuyc1 ,

The console output is the value counted in the L2 adapter layer. Since CRC errors are counted, the UL U-plane packets were received correctly, but all the PUSCH allocations seemed to be CRC errors.

Can you share an nvipc.pcap file?

Just in case, the FAPI message format for OAI is based on v10.02. Did you use the following compilation options written here?

aerial@c_aerial_user:/opt/nvidia/cuBB$ ${cuBB_SDK}/testBenches/phase4_test_scripts/build_aerial_sdk.sh --preset 10_02 -- -DSCF_FAPI_10_04_SRS=ON

Thank you.

6

thanks @nhashimoto

Now I use
Introduction — Aerial Testbed

the fapi pcap is collected via pcap cmd.
nvipc.zip (22.7 KB)

$ sudo docker logs nv-cubb 2>&1 | grep -E "FAPI|nfapi|rx_msg|msg_id|msg_type|CONFIG|DL_SCHED|P5|P7"
[sudo] password for wangderingalex:
Applying RU_MAC=bc:87:53:01:01:8b to first dst_mac_addr in /opt/nvidia/cuBB/cuPHY-CP/cuphycontroller/config/cuphycontroller_P5G_WNC_DGX.yaml
20:53:57.391753 CON phy_init 0 [CTL.SCF] Config file: /opt/nvidia/cuBB/cuPHY-CP/cuphycontroller/config/cuphycontroller_P5G_WNC_DGX.yaml
20:53:57.392400 CON phy_init 0 [APP.CONFIG] Current TAI offset: 0s
20:53:57.421743 CON phy_init 0 [CTL.YAML] L2Adapter config file: /opt/nvidia/cuBB/cuPHY-CP/cuphycontroller/config/l2_adapter_config_P5G_DGX.yaml
20:54:09.272802 CON phy_main 0 [CTL.STARTUP_TIMES] {TI PERCENTAGE} <cuphycontroller main> Start Main:0.0,Parse Cuphycontroller YAML:0.0,Init nvlog:0.2,Cuda Set Device:2.2,Cuphy PTI Init:1.1,Init PHYDriver:90.0,Init cuphydriver:0.0,Make PHYDriverProxy:0.0,Init SCF FAPI:0.0,Create PHY_group:6.4,Start PHY_group:0.0, (total: 11885250.7us),
20:54:09.272807 CON phy_main 0 [CTL.STARTUP_TIMES] {TI DURATION} <cuphycontroller main> Start Main:4142.674,Parse Cuphycontroller YAML:738.077,Init nvlog:29327.247,Cuda Set Device:260112.318,Cuphy PTI Init:132481.127,Init PHYDriver:10695271.536,Init cuphydriver:0.288,Make PHYDriverProxy:7.248,Init SCF FAPI:0.464,Create PHY_group:762847.429,Start PHY_group:322.287,
20:54:09.272809 CON phy_main 0 [CTL.STARTUP_TIMES] {TI TIMESTAMPS} <cuphycontroller main> Start Main:1803237387540288,Parse Cuphycontroller YAML:1803237391682962,Init nvlog:1803237392421039,Cuda Set Device:1803237421748286,Cuphy PTI Init:1803237681860604,Init PHYDriver:1803237814341731,Init cuphydriver:1803248509613267,Make PHYDriverProxy:1803248509613555,Init SCF FAPI:1803248509620803,Create PHY_group:1803248509621267,Start PHY_group:1803249272468696,End Main:1803249272790983,
20:54:10.626222 WRN msg_processing 0 [SCF.PHY] on_msg: Incorrect msg length cell_id=0 msg_id=0x02 expected=613 received=621
20:54:10.626232 CON msg_processing 0 [SCF.PHY] on_config_request: CONFIG.req received for cell_id=0 numTLVs=38 state=0
20:54:10.730878 CON msg_processing 0 [SCF.PHY] send_cell_config_response: Send CONFIG.response: cell_id=0 error_code=0x0
20:54:10.731364 WRN msg_processing 0 [SCF.PHY] on_msg: Incorrect msg length cell_id=0 msg_id=0x04 expected=8 received=16
7

Thank you, @xuyc1 , but the PCAP doesn’t contain any PUSCH PDUs. Can you capture a FAPI log while you observe CRC errors?

8

thanks @nhashimoto , now the crc seem always 0

21:40:32.930452 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5550000
21:40:33.360862 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 38.19 Slot Map 37 cell index 0 Dyn index -1 setting as healthy!
21:40:33.382385 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 40.19 Slot Map 39 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F39S9S1 done = 1 current_time=64031692201536,last_timeout_log_time=64030672199328
21:40:33.930452 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5552000
21:40:34.380860 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 140.19 Slot Map 139 cell index 0 Dyn index -1 setting as healthy!
21:40:34.402385 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 142.19 Slot Map 141 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F141S9S1 done = 1 current_time=64032712206112,last_timeout_log_time=64031692201536
21:40:34.930451 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5554000
21:40:35.400860 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 242.19 Slot Map 241 cell index 0 Dyn index -1 setting as healthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F243S9S1 done = 1 current_time=64033732211424,last_timeout_log_time=64032712206112
21:40:35.422390 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 244.19 Slot Map 243 cell index 0 Dyn index -1 setting as unhealthy!
21:40:35.930452 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5556000
21:40:36.420861 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 344.19 Slot Map 343 cell index 0 Dyn index -1 setting as healthy!
21:40:36.442382 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 346.19 Slot Map 345 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F89S9S1 done = 1 current_time=64034752215136,last_timeout_log_time=64033732211424
21:40:36.930451 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5558000
21:40:37.440862 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 446.19 Slot Map 445 cell index 0 Dyn index -1 setting as healthy!
21:40:37.462386 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 448.19 Slot Map 447 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F191S9S1 done = 1 current_time=64035772215264,last_timeout_log_time=64034752215136
21:40:37.930451 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5560000
21:40:38.460861 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 548.19 Slot Map 35 cell index 0 Dyn index -1 setting as healthy!
21:40:38.482385 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 550.19 Slot Map 37 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F37S9S1 done = 1 current_time=64036792218944,last_timeout_log_time=64035772215264
21:40:38.930451 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5562000
21:40:39.480862 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 650.19 Slot Map 137 cell index 0 Dyn index -1 setting as healthy!
21:40:39.502389 ERR UlPhyDriver05 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 652.19 Slot Map 139 cell index 0 Dyn index -1 setting as unhealthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F139S9S1 done = 1 current_time=64037812223232,last_timeout_log_time=64036792218944
21:40:39.930452 CON timer_thread 0 [SCF.PHY] Cell  0 | DL    0.04 Mbps   50 Slots | UL    0.00 Mbps    0 Slots CRC   0 (     0) | Tick 5564000
21:40:40.500859 ERR UlPhyDriver06 0 [AERIAL_CUPHY_API_EVENT] [DRV.FUNC_UL] SFN 752.19 Slot Map 239 cell index 0 Dyn index -1 setting as healthy!
3952 Cell 0 Order kernel sem_idx_rx 0 last_sem_idx_rx 0 sem_idx_order 0 last_sem_idx_order 0 PUSCH PRBs 0/0 PRACH PRBs 0/576. No packet received timeout after 3000000 ns F241S9S1 done = 1
9

The screenshot is indicating that any UL U-plane packets did not arrive at the DU side. This is why the Aerial was frequently transitioning to the unhealthy mode.
What change did you do?

10

Thanks @nhashimoto ,

no change was made, the CRC is 0 too in the screen snapshot I posted before.

Now there is no grandmaster, o-ru can receive the c/u plane packet but report “too early”, so I don’t expect any UL traffic from RU.

11

According to the screenshot you shared on September 5, it appears that several CRC errors were detected during the test. I reattached it.

image
image1804×610 74.1 KB

BTW, if the O-RU is connecting to your DU server directly and doesn’t need SyncE, you can run PTP as master on the server.

12

thanks @nhashimoto ,

I remembered that I configure the RU_TYPE as 3 at the beginning, later try the 2,1, This is only change I made.

The DU and RU are connected via switch, acting as PTP slave while the switch act as master. Now the switch has some sw bug, its P0.TP output stay in year 1970.

13

If the switch supports PTP, why don’t you configure the DU server as master and the switch as boundary clock?

14

thanks @nhashimoto

the switch support the ptp.
The DU use 400G QSFP, the ORU only support 10G SFP, they might can’t be connected directly.

15

Please configure RU_TYPE: 1 if the O-RU is with mtu_size: 8192.
If this is supported on Switch, please configure the switch port connecting to DU as slave, and the port connecting to O-RU as master clock. Also need to configure DU server as master clock. It is OK to have 400G QSFP at DU and 10G SFP at 10G.

16

thanks @nhashimoto @jixu

You mean C1 mode, can the UE attach the network in such configuration?