srsran / srsRAN_4G

Open source SDR 4G software suite from Software Radio Systems (SRS) https://docs.srsran.com/projects/4g
https://www.srsran.com
GNU Affero General Public License v3.0
3.45k stars 1.14k forks source link

5G SA COST UE Error :Disconnecting rnti=0x4603. #882

Closed coolcoollly closed 2 years ago

coolcoollly commented 2 years ago

Issue Description

[Describe the issue in detail] I build the gnb and open5gs core with the tutorial (https://docs.srsran.com/en/latest/app_notes/source/5g_sa_COTS/source/index.html). I build the gnb and open5gs core successfully and NG connection successful. My handset(Honor X10) can register the network operator(00101), but the handset can not connect to internet and the gnb window print : RACH: slot=9131, cc=0, preamble=4, offset=0, temp_crnti=0x4601 RACH: slot=9291, cc=0, preamble=3, offset=0, temp_crnti=0x4602 RACH: slot=2731, cc=0, preamble=5, offset=0, temp_crnti=0x4603 Disconnecting rnti=0x4603. RACH: slot=2891, cc=0, preamble=3, offset=0, temp_crnti=0x4604 Disconnecting rnti=0x4604. RACH: slot=8331, cc=0, preamble=6, offset=84, temp_crnti=0x4605 Disconnecting rnti=0x4602.

Setup Details

[Specify details of the test setup. This would help us reproduce the problem reliably] srsRAN 22.04; open5gs; linux 18.04; uhd 3.15; usrp X310;

Expected Behavior

gnb and open5gs core are built successfully and NG connection successful. My handset can connect to internet with my 5G network operator.

Actual Behaviour

gnb and open5gs core are built successfully and NG connection successful. My handset(Honor X10) can register the network operator(00101), but the handset can not connect to internet and the gnb window print : RACH: slot=9131, cc=0, preamble=4, offset=0, temp_crnti=0x4601 RACH: slot=9291, cc=0, preamble=3, offset=0, temp_crnti=0x4602 RACH: slot=2731, cc=0, preamble=5, offset=0, temp_crnti=0x4603 Disconnecting rnti=0x4603. RACH: slot=2891, cc=0, preamble=3, offset=0, temp_crnti=0x4604 Disconnecting rnti=0x4604. RACH: slot=8331, cc=0, preamble=6, offset=84, temp_crnti=0x4605 Disconnecting rnti=0x4602. 82217D1EFD99990A7702B47F5060C822 2022-06-03 10-13-40 的屏幕截图

Steps to reproduce the problem

[Tell us how to reproduce this issue e.g. RF setup, application config files] amf.txt upf.txt enb.txt rr.txt

this is my enb.log : enb.log 2022-06-03T02:30:50.859260 [ENB ] [I] Using binary ./srsenb with arguments: /home/uavbs/.config/srsran/enb.conf 2022-06-03T02:30:50.903756 [ENB ] [I] Built in Release mode using commit f2dff0b7a on branch master. 2022-06-03T02:31:24.666475 [MAC-NR ] [W] [ 9386] Unhandled subPDU with LCID=57 2022-06-03T02:31:30.669046 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:31:36.674995 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:31:42.679126 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:31:44.189922 [MAC-NR ] [W] [ 8428] Unhandled subPDU with LCID=57 2022-06-03T02:31:44.255038 [MAC-NR ] [W] [ 8495] SCHED: "ul_crc_info" called for unknown rnti=0x4602,cc=0. 2022-06-03T02:31:49.227912 [MAC-NR ] [W] [ 3228] Unhandled subPDU with LCID=57 2022-06-03T02:31:50.427293 [MAC-NR ] [W] [ 4427] Unhandled subPDU with LCID=57 2022-06-03T02:31:50.626749 [MAC-NR ] [W] [ 4626] Unhandled subPDU with LCID=57 2022-06-03T02:31:50.826813 [MAC-NR ] [W] [ 4827] Unhandled subPDU with LCID=57 2022-06-03T02:31:50.831847 [NGAP ] [W] Not handling UEAggregateMaximumBitRate 2022-06-03T02:31:50.831848 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:31:51.026810 [PDCP-NR] [E] MAC mismatch (expected) 0000: e5 30 86 ee 2022-06-03T02:31:51.026811 [PDCP-NR] [E] MAC mismatch (found) 0000: 00 00 00 00 2022-06-03T02:31:51.026813 [PDCP-NR] [W] Integrity check input: COUNT 3, Bearer ID 1, Direction Uplink 2022-06-03T02:31:51.026813 [PDCP-NR] [W] Integrity check key: 0000: 49 4f 80 a8 b7 0b 43 6c 7a 51 29 bc c8 ac 31 ce 0010: c7 6a 37 5a 36 4d d9 4f ce 4e 3a dd d3 4d 4d 21 2022-06-03T02:31:51.026813 [PDCP-NR] [W] Integrity check input msg (Bytes=4): 0000: 00 03 36 00 2022-06-03T02:31:51.026814 [PDCP-NR] [E] SRB1 Dropping PDU 0000: 00 03 36 00 2022-06-03T02:31:51.026818 [PDCP-NR] [E] MAC mismatch (expected) 0000: 2b 1a 38 b6 2022-06-03T02:31:51.026818 [PDCP-NR] [E] MAC mismatch (found) 0000: 00 00 00 00 2022-06-03T02:31:51.026818 [PDCP-NR] [W] Integrity check input: COUNT 4, Bearer ID 1, Direction Uplink 2022-06-03T02:31:51.026818 [PDCP-NR] [W] Integrity check key: 0000: 49 4f 80 a8 b7 0b 43 6c 7a 51 29 bc c8 ac 31 ce 0010: c7 6a 37 5a 36 4d d9 4f ce 4e 3a dd d3 4d 4d 21 2022-06-03T02:31:51.026819 [PDCP-NR] [W] Integrity check input msg (Bytes=15): 0000: 00 04 3a 05 3f 01 3f 70 62 ec 80 bf 00 21 80 2022-06-03T02:31:51.026819 [PDCP-NR] [E] SRB1 Dropping PDU 0000: 00 04 3a 05 3f 01 3f 70 62 ec 80 bf 00 21 80 2022-06-03T02:31:51.026822 [MAC-NR ] [W] [ 5026] Unhandled subPDU with LCID=57 2022-06-03T02:31:54.422831 [NGAP ] [W] Released UE rnti=0x4601 not found. 2022-06-03T02:31:56.837152 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:31:56.867175 [MAC-NR ] [W] [ 626] Unhandled subPDU with LCID=57 2022-06-03T02:32:01.946922 [MAC-NR ] [W] [ 5706] Unhandled subPDU with LCID=57 2022-06-03T02:32:01.985713 [MAC-NR ] [W] [ 5745] Unhandled subPDU with LCID=57 2022-06-03T02:32:02.838160 [NGAP ] [W] Not handling AllowedNSSAI 2022-06-03T02:32:03.066988 [MAC-NR ] [W] [ 6826] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.105700 [MAC-NR ] [W] [ 6865] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.410305 [MAC-NR ] [W] [ 7170] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.617945 [MAC-NR ] [W] [ 7378] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.657854 [MAC-NR ] [W] [ 7416] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.698687 [MAC-NR ] [W] [ 7458] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.898808 [MAC-NR ] [W] [ 7658] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.945289 [MAC-NR ] [W] [ 7705] Unhandled subPDU with LCID=57 2022-06-03T02:32:03.986820 [MAC-NR ] [W] [ 7746] Unhandled subPDU with LCID=57 2022-06-03T02:32:04.146493 [MAC-NR ] [W] [ 7906] Unhandled subPDU with LCID=57 2022-06-03T02:32:08.538202 [MAC-NR ] [W] [ 2058] Unhandled subPDU with LCID=57 2022-06-03T02:32:08.542299 [STCK ] [I] Bearers: Registered eps-BearerID=1 for rnti=0x460d, lcid=4 over NR-PDCP 2022-06-03T02:32:09.546662 [MAC-NR ] [W] [ 3066] Unhandled subPDU with LCID=57 2022-06-03T02:32:09.547106 [NGAP ] [W] Removing pdu_session=17933 from GTPU 2022-06-03T02:32:09.586062 [MAC-NR ] [W] [ 3106] Unhandled subPDU with LCID=57 2022-06-03T02:32:09.610037 [MAC-NR ] [W] [ 3128] SCHED: "ul_sr_info" called for unknown rnti=0x460d. 2022-06-03T02:32:09.626916 [MAC-NR ] [W] [ 3147] Unhandled subPDU with LCID=57 2022-06-03T02:32:09.666049 [MAC-NR ] [W] [ 3186] Unhandled subPDU with LCID=57 2022-06-03T02:32:12.818253 [MAC-NR ] [W] [ 6338] Unhandled subPDU with LCID=57 2022-06-03T02:32:12.857189 [MAC-NR ] [W] [ 6377] Unhandled subPDU with LCID=57 2022-06-03T02:32:42.818689 [NGAP ] [W] Removing pdu_session=17934 from GTPU 2022-06-03T02:32:42.881072 [MAC-NR ] [W] [ 5681] SCHED: "dl_cqi_info" called for unknown rnti=0x460e,cc=0. 2022-06-03T02:33:24.987321 [MAC-NR ] [W] [ 6827] Unhandled subPDU with LCID=57 2022-06-03T02:33:25.025966 [MAC-NR ] [W] [ 6866] Unhandled subPDU with LCID=57 2022-06-03T02:33:25.067386 [MAC-NR ] [W] [ 6907] Unhandled subPDU with LCID=57 2022-06-03T02:33:25.106190 [MAC-NR ] [W] [ 6946] Unhandled subPDU with LCID=57 2022-06-03T02:33:28.586330 [MAC-NR ] [W] [ 186] Unhandled subPDU with LCID=57 2022-06-03T02:33:43.098362 [MAC-NR ] [W] [ 4458] Unhandled subPDU with LCID=57 2022-06-03T02:33:43.099143 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:33:58.138389 [MAC-NR ] [W] [ 9258] Unhandled subPDU with LCID=57 2022-06-03T02:33:58.139258 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:34:13.138397 [MAC-NR ] [W] [ 3778] Unhandled subPDU with LCID=57 2022-06-03T02:34:13.139376 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:34:28.137977 [MAC-NR ] [W] [ 8538] Unhandled subPDU with LCID=57 2022-06-03T02:34:28.138931 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:34:43.138576 [MAC-NR ] [W] [ 3058] Unhandled subPDU with LCID=57 2022-06-03T02:34:43.139454 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:34:58.138487 [MAC-NR ] [W] [ 7818] Unhandled subPDU with LCID=57 2022-06-03T02:34:58.139363 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:35:13.138652 [MAC-NR ] [W] [ 2338] Unhandled subPDU with LCID=57 2022-06-03T02:35:13.139449 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure 2022-06-03T02:35:28.146423 [MAC-NR ] [W] [ 7106] Unhandled subPDU with LCID=57 2022-06-03T02:35:28.147394 [NGAP ] [E] Failed to start UE PDU Session Resource Setup Procedure

Additional Information

[Any additional information, configuration or data that might be necessary to reproduce the issue]

andrepuschmann commented 2 years ago

Hey! Could you please rerun the experiment with eNB logs set to info level. and provide the logs? Also send the PCAP for the eNB. Thanks

coolcoollly commented 2 years ago

Hey! Could you please rerun the experiment with eNB logs set to info level. and provide the logs? Also send the PCAP for the eNB. Thanks

Hey! I rerun the experiment and get the eNB logs set to info level and enb_mac_nr.pcap. And there is the same problem on enb window. enb.log enb_mac_nr.zip 2022-06-03 16-28-34 的屏幕截图

andrepuschmann commented 2 years ago

Hey, the eNB logs show a few RF underruns and it should be good if they would go away. Not sure how powerful your computer is but make sure you have the CPU governor set to performance and maybe try to reduce the PUSCH MCS. Also, could you please give this branch a try. It includes a few RLC and PDCP fixes. Provide logs/PCAP again. Thanks

coolcoollly commented 2 years ago

Hey, the eNB logs show a few RF underruns and it should be good if they would go away. Not sure how powerful your computer is but make sure you have the CPU governor set to performance and maybe try to reduce the PUSCH MCS. Also, could you please give this branch a try. It includes a few RLC and PDCP fixes. Provide logs/PCAP again. Thanks

Hey, this is my computer CPU: Intel® Core™ i5-6500 CPU @ 3.20GHz × 4 . My CPU governor has been set to performance. And I used the same equipments to run 4G COST UE successfully. I tried to set both nr_pdsch_mcs and nr_pusch_mcs to 27,10,2,1, but the result is same(my phone Honor X10 can register the network operator(00101), but the handset can not connect to internet and the gnb window print disconnected). Then I modify my files in srsran/lib , srsran/srsgnb and srsran/srsue by the branch given above. And I run srsran/build/srsenb/src/srsenb again setting both nr_pdsch_mcs and nr_pusch_mcs to 10, but the problem is same. I give my enb.log and enb_mac_nr.pdcp in this run. enb_mac_nr.zip enb.log This is the branch I found: 2022-06-14 17-29-17 的屏幕截图 Finally I am very suspicious that my phone(Honor X10 ) have the problem to connect to the gnb, so I want to buy a phone used in the the tutorial (https://docs.srsran.com/en/latest/app_notes/source/5g_sa_COTS/source/index.html). Do you have more information about Oneplus Nord 5G? Is Oneplus Nord 5G like the picture? 6CD8888C2347F2F297E6246578B1B15B

andrepuschmann commented 2 years ago

This is the same issue as #886. I know this was flagged earlier, but #886 is more descriptive. Closing it and tracking state there.