srsRAN_4G icon indicating copy to clipboard operation
srsRAN_4G copied to clipboard

NSA srsue can't connect

Open LongRiver-hash opened this issue 2 years ago • 1 comments

Issue Description

[Describe the issue in detail] I have been trying to make a 5G NSA end-to-end connection as the websites srsran provided with zmq,but there is no random access and I dont't know why.I also attmeped two SDR B210,the problem seems more.

Setup Details

[Specify details of the test setup. This would help us reproduce the problem reliably] e.g. Network configuration, Operation System, Hardware, RF front-end, library and driver versions srsepc and srsenb machine:ubuntu 20.04,UHD3.15,srsran 22.04 srsue machine:ubuntu 18.04,UHD3.15,srsran 22.04 using zmq or B210 the configuration file is default as srsran websites provided.

Expected Behavior

[What you expect to happen] zmq:appear random access,srsue connect srsenb B210:appear random access,srsue connect srsenb

Actual Behaviour

[What happens instead e.g. error message] zmq:the message stopped at Attach UE ...the logger as follows srsenb1.log, srsue1.log B210:it seems has synchronization problem,the logger as follows srsenb2.log, srsue2.log

srsenb1.log: 2022-07-12T07:35:24.060487 [ENB ] [I] Using binary srsenb with arguments: 2022-07-12T07:35:24.090967 [ENB ] [I] Built in Release mode using 22.04.0. 2022-07-12T07:35:24.092200 [ENB ] [I] Using sync queue size of one for ZMQ based radio. 2022-07-12T07:35:24.140498 [RRC ] [I] Tx Broadcast PDU - systemInformationBlockType1, cc=0, idx=0 (15 B) 0000: 40 40 04 03 00 07 00 19 b0 18 14 60 10 82 80 2022-07-12T07:35:24.140522 [RRC ] [I] Tx Broadcast PDU - systemInformation-r8, cc=0, idx=1 (37 B) 0000: 00 82 0c e1 bf 78 88 00 ca 11 e0 01 00 00 08 01 0010: 82 99 45 ab 9c 30 c6 a6 cc c1 c4 80 20 31 01 0a 2022-07-12T07:35:24.140530 [RRC ] [I] Allocating 1 PRBs for PUCCH 2022-07-12T07:35:24.140772 [MAC ] [I] [ 0] Using time-domain PF scheduling policy for cc=0 2022-07-12T07:35:24.140842 [RRC ] [I] T310 200, T311 10000, N310 1 2022-07-12T07:35:24.140846 [RRC ] [I] Inactivity timeout: 30000 ms 2022-07-12T07:35:24.140849 [RRC ] [I] Max consecutive MAC KOs: 100 2022-07-12T07:35:24.140866 [S1AP ] [I] Proc "MME Connection" - Starting new MME connection. 2022-07-12T07:35:24.140869 [S1AP ] [I] Connecting to MME 127.0.1.100:36412 2022-07-12T07:35:24.140946 [COMN ] [D] [ 0] Setting RTO_INFO options on SCTP socket. Association 0, Initial RTO 3000, Minimum RTO 1000, Maximum RTO 6000 2022-07-12T07:35:24.140949 [COMN ] [D] [ 0] Setting SCTP_INITMSG options on SCTP socket. Max attempts 3, Max init attempts timeout 5000 2022-07-12T07:35:24.140987 [COMN ] [D] [ 0] Successfully bound to address 127.0.1.1:0 2022-07-12T07:35:24.140988 [S1AP ] [I] SCTP socket opened. fd=7 2022-07-12T07:35:24.141246 [S1AP ] [I] SCTP socket connected with MME. fd=7 2022-07-12T07:35:24.141269 [COMN ] [D] [ 0] RxSockets: socket fd=7 has been registered. 2022-07-12T07:35:24.141271 [S1AP ] [I] SCTP socket established with MME 2022-07-12T07:35:24.141343 [S1AP ] [I] Tx S1AP SDU, s1SetupRequest 0000: 00 11 00 2d 00 00 04 00 3b 00 08 00 00 f1 10 00 0010: 00 19 b0 00 3c 40 0a 03 80 73 72 73 65 6e 62 30 2022-07-12T07:35:24.141460 [S1AP ] [I] Proc "MME Connection" - S1SetupRequest sent. Waiting for response... 2022-07-12T07:35:24.141559 [COMN ] [D] [ 0] Successfully bound to address 127.0.1.1:2152 2022-07-12T07:35:24.141573 [COMN ] [D] [ 0] RxSockets: socket fd=8 has been registered. 2022-07-12T07:35:24.146366 [MAC-NR ] [I] [ 0] Started 2022-07-12T07:35:24.146386 [RRC-NR ] [I] Cell idx=0, pci=500, nr_dl_arfcn=368500, nr_ul_arfcn=349500, band=3, duplex=FDD, n_rb_dl=52, ssb_arfcn=367930 2022-07-12T07:35:24.146399 [RRC-NR ] [I] BCCH-BCH Message (with MIB) (3 B) 0000: 00 63 04 2022-07-12T07:35:24.146426 [RRC-NR ] [I] MIB content: { "systemFrameNumber": "000000", "subCarrierSpacingCommon": "scs15or60", "ssb-SubcarrierOffset": 6, "dmrs-TypeA-Position": "pos2", "pdcch-ConfigSIB1": { "controlResourceSetZero": 6, "searchSpaceZero": 0 }, "cellBarred": "notBarred", "intraFreqReselection": "allowed", "spare": "0" } 2022-07-12T07:35:24.149779 [S1AP ] [I] Rx S1AP SDU - S1SetupResponse 0000: 20 11 00 25 00 00 03 00 3d 40 0a 03 80 73 72 73 0010: 6d 6d 65 30 31 00 69 00 0b 00 00 00 f1 10 00 00 2022-07-12T07:35:24.149792 [S1AP ] [I] Proc "MME Connection" - S1Setup procedure completed successfully 2022-07-12T07:35:24.205281 [RRC-NR ] [I] Number of 5QI 2 2022-07-12T07:35:24.205284 [RRC-NR ] [I] 5QI configuration. 5QI=7 2022-07-12T07:35:24.205295 [RRC-NR ] [I] PDCP NR configuration: { "drb": { "discardTimer": "ms50", "pdcp-SN-SizeUL": "len18bits", "pdcp-SN-SizeDL": "len18bits", "headerCompression": { } }, "t-Reordering": "ms50" } 2022-07-12T07:35:24.205301 [RRC-NR ] [I] RLC NR configuration: { "um-Bi-Directional": { "ul-UM-RLC": { "sn-FieldLength": "size12" }, "dl-UM-RLC": { "sn-FieldLength": "size12", "t-Reassembly": "ms50" } } } 2022-07-12T07:35:24.205303 [RRC-NR ] [I] 5QI configuration. 5QI=9 2022-07-12T07:35:24.205306 [RRC-NR ] [I] PDCP NR configuration: { "drb": { "discardTimer": "ms50", "pdcp-SN-SizeUL": "len18bits", "pdcp-SN-SizeDL": "len18bits", "headerCompression": { } }, "t-Reordering": "ms50" } 2022-07-12T07:35:24.205313 [RRC-NR ] [I] RLC NR configuration: { "am": { "ul-AM-RLC": { "sn-FieldLength": "size12", "t-PollRetransmit": "ms50", "pollPDU": "p4", "pollByte": "kB3000", "maxRetxThreshold": "t4" }, "dl-AM-RLC": { "sn-FieldLength": "size12", "t-Reassembly": "ms50", "t-StatusProhibit": "ms50" } } } 2022-07-12T07:35:24.205315 [RRC-NR ] [I] NIA preference list: NIA0, NIA0, NIA0 2022-07-12T07:35:24.205316 [RRC-NR ] [I] NEA preference list: NEA0, NEA0, NEA0 2022-07-12T07:35:24.206993 [RF ] [I] Configuring physical DL channel 0 with band-pass filter (0.0, 0.0) 2022-07-12T07:35:24.206994 [RF ] [I] Configuring physical UL channel 0 with band-pass filter (0.0, 0.0) 2022-07-12T07:35:24.206996 [RF ] [I] Configuring physical DL channel 1 with band-pass filter (0.0, 0.0) 2022-07-12T07:35:24.206997 [RF ] [I] Configuring physical UL channel 1 with band-pass filter (0.0, 0.0) 2022-07-12T07:35:24.571519 [PHY0 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.571575 [PHY0 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.683712 [PHY1 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.683754 [PHY1 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.798148 [PHY2 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.798178 [PHY2 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-12T07:35:24.832386 [PHY-NR ] [I] [ 0] Setting SSB configuration srate=11.52 MHz; c-freq=1842.500 MHz; ss-freq=1839.650 MHz; scs=15kHz; pattern=A; duplex=fdd; period=10 ms; 2022-07-12T07:35:24.843254 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_tx=2680.0 MHz 2022-07-12T07:35:24.843265 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_rx=2560.0 MHz 2022-07-12T07:35:24.843308 [RF ] [I] Mapping RF channel 1 (device=0, channel=1) to logical carrier 1 on f_tx=1842.5 MHz 2022-07-12T07:35:24.843309 [RF ] [I] Mapping RF channel 1 (device=0, channel=1) to logical carrier 1 on f_rx=1747.5 MHz 2022-07-12T07:35:24.843311 [PHY ] [I] [ 0] Starting RX/TX thread nof_prb=50, sf_len=11520 2022-07-12T07:41:59.022347 [S1AP ] [I] SCTP Notification 8005 2022-07-12T07:41:59.022352 [S1AP ] [I] SCTP Association Shutdown. Association: 0 2022-07-12T07:41:59.022380 [S1AP ] [I] Restarting S1 connection 2022-07-12T07:41:59.022582 [S1AP ] [I] Proc "MME Connection" - Starting new MME connection. 2022-07-12T07:41:59.022587 [S1AP ] [I] Connecting to MME 127.0.1.100:36412 2022-07-12T07:41:59.022683 [S1AP ] [I] SCTP socket opened. fd=7 2022-07-12T07:41:59.022794 [COMN ] [I] [ 0] Failed to establish socket connection to 127.0.1.100 2022-07-12T07:41:59.022833 [S1AP ] [I] Proc "MME Connection" - Could not connect to MME 2022-07-12T07:41:59.022836 [S1AP ] [I] Proc "MME Connection" - Failed to initiate S1 connection. Attempting reconnection in 10 seconds 2022-07-12T07:41:59.022858 [COMN ] [W] [ 0] RxSockets: The socket fd=7 to be removed does not exist 2022-07-12T07:41:59.022873 [S1AP ] [I] Proc "MME Connection" - S1AP socket closed.

srsue1.log 2022-07-12T07:36:23.547837 [UE ] [I] Using binary srsue with arguments: 2022-07-12T07:36:23.595603 [UE ] [I] Built in Release mode using 22.04.0. 2022-07-12T07:36:23.649890 [RF ] [I] Configuring physical DL channel 0 with band-pass filter (0.0, 0.0) 2022-07-12T07:36:23.649891 [RF ] [I] Configuring physical UL channel 0 with band-pass filter (0.0, 0.0) 2022-07-12T07:36:23.649892 [RF ] [I] Configuring physical DL channel 1 with band-pass filter (0.0, 0.0) 2022-07-12T07:36:23.649892 [RF ] [I] Configuring physical UL channel 1 with band-pass filter (0.0, 0.0) 2022-07-12T07:36:23.779047 [STCK ] [E] Unknown PCAP option true 2022-07-12T07:36:23.785572 [MAC ] [I] [ 0] Resetting MAC 2022-07-12T07:36:23.785578 [MAC ] [I] [ 0] Logical Channel Setup: LCID=0, LCG=0, priority=0, PBR=-1, BSD=50ms, bucket_size=0 2022-07-12T07:36:23.785581 [MAC ] [I] [ 0] Logical Channel Setup: LCID=1, LCG=0, priority=1, PBR=-1, BSD=50ms, bucket_size=0 2022-07-12T07:36:23.785594 [MAC ] [I] [ 0] Setting configuration 2022-07-12T07:36:23.785595 [MAC ] [I] [ 0] BSR: Configured timer reTX 2560 ms 2022-07-12T07:36:23.785603 [RLC ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode 2022-07-12T07:36:23.785628 [USIM ] [I] Read Home PLMN Id=00101 2022-07-12T07:36:23.785906 [NAS ] [I] Read GUTI from file m_tmsi: 134f4773, mcc: 1, mnc: 1, mme_group_id: 1, mme_code: 1a 2022-07-12T07:36:23.785918 [NAS ] [I] Read security ctxt from file .ctxt. ksi: 0, k_asme: da2c4c9d6d9f24faca9f5f9666fa57cd4c07822e6a19cd4ec1b48cdff9215e76, tx_count: 3, rx_count: 3, int_alg: 1, enc_alg: 0 2022-07-12T07:36:23.785919 [RRC ] [I] Set ue-Identity to 0x26:0x323962739 2022-07-12T07:36:23.790238 [RLC-NR ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode 2022-07-12T07:36:23.790247 [RRC ] [I] using srand seed of 790247 2022-07-12T07:36:24.163056 [STCK ] [I] Triggering NAS switch on 2022-07-12T07:36:24.163698 [NAS ] [I] Switching on 2022-07-12T08:01:01.844337 [NAS ] [I] Switching off 2022-07-12T08:01:02.161636 [NAS ] [I] Saved GUTI to file m_tmsi: 134f4773, mcc: 1, mnc: 1, mme_group_id: 1, mme_code: 1a 2022-07-12T08:01:02.161641 [NAS ] [I] Saved security ctxt to file .ctxt. ksi: 0, k_asme: da2c4c9d6d9f24faca9f5f9666fa57cd4c07822e6a19cd4ec1b48cdff9215e76, tx_count: 3, rx_count: 3, int_alg: 1, enc_alg: 0

srsenb2.log 2022-07-15T00:18:39.616941 [ENB ] [I] Using binary srsenb with arguments: 2022-07-15T00:18:39.651321 [ENB ] [I] Built in Release mode using 22.04.0. 2022-07-15T00:18:39.715613 [RRC ] [I] Tx Broadcast PDU - systemInformationBlockType1, cc=0, idx=0 (15 B) 0000: 40 40 04 03 00 07 00 19 b0 18 14 60 10 82 80 2022-07-15T00:18:39.715631 [RRC ] [I] Tx Broadcast PDU - systemInformation-r8, cc=0, idx=1 (37 B) 0000: 00 82 0c e1 bf 78 88 00 ca 11 e0 01 00 00 08 01 0010: 82 99 45 ab 9c 30 c6 a6 cc c1 c4 80 20 31 01 0a 2022-07-15T00:18:39.715637 [RRC ] [I] Allocating 1 PRBs for PUCCH 2022-07-15T00:18:39.715975 [MAC ] [I] [ 0] Using time-domain PF scheduling policy for cc=0 2022-07-15T00:18:39.716047 [RRC ] [I] T310 200, T311 10000, N310 1 2022-07-15T00:18:39.716049 [RRC ] [I] Inactivity timeout: 30000 ms 2022-07-15T00:18:39.716052 [RRC ] [I] Max consecutive MAC KOs: 100 2022-07-15T00:18:39.716074 [S1AP ] [I] Proc "MME Connection" - Starting new MME connection. 2022-07-15T00:18:39.716076 [S1AP ] [I] Connecting to MME 127.0.1.100:36412 2022-07-15T00:18:39.716121 [COMN ] [D] [ 0] Setting RTO_INFO options on SCTP socket. Association 0, Initial RTO 3000, Minimum RTO 1000, Maximum RTO 6000 2022-07-15T00:18:39.716124 [COMN ] [D] [ 0] Setting SCTP_INITMSG options on SCTP socket. Max attempts 3, Max init attempts timeout 5000 2022-07-15T00:18:39.716138 [COMN ] [D] [ 0] Successfully bound to address 127.0.1.1:0 2022-07-15T00:18:39.716140 [S1AP ] [I] SCTP socket opened. fd=7 2022-07-15T00:18:39.716254 [S1AP ] [I] SCTP socket connected with MME. fd=7 2022-07-15T00:18:39.716271 [COMN ] [D] [ 0] RxSockets: socket fd=7 has been registered. 2022-07-15T00:18:39.716273 [S1AP ] [I] SCTP socket established with MME 2022-07-15T00:18:39.716303 [S1AP ] [I] Tx S1AP SDU, s1SetupRequest 0000: 00 11 00 2d 00 00 04 00 3b 00 08 00 00 f1 10 00 0010: 00 19 b0 00 3c 40 0a 03 80 73 72 73 65 6e 62 30 2022-07-15T00:18:39.716371 [S1AP ] [I] Proc "MME Connection" - S1SetupRequest sent. Waiting for response... 2022-07-15T00:18:39.716408 [COMN ] [D] [ 0] Successfully bound to address 127.0.1.1:2152 2022-07-15T00:18:39.716419 [COMN ] [D] [ 0] RxSockets: socket fd=8 has been registered. 2022-07-15T00:18:39.722948 [MAC-NR ] [I] [ 0] Started 2022-07-15T00:18:39.722967 [RRC-NR ] [I] Cell idx=0, pci=500, nr_dl_arfcn=368500, nr_ul_arfcn=349500, band=3, duplex=FDD, n_rb_dl=52, ssb_arfcn=367930 2022-07-15T00:18:39.722982 [RRC-NR ] [I] BCCH-BCH Message (with MIB) (3 B) 0000: 00 63 04 2022-07-15T00:18:39.723021 [RRC-NR ] [I] MIB content: { "systemFrameNumber": "000000", "subCarrierSpacingCommon": "scs15or60", "ssb-SubcarrierOffset": 6, "dmrs-TypeA-Position": "pos2", "pdcch-ConfigSIB1": { "controlResourceSetZero": 6, "searchSpaceZero": 0 }, "cellBarred": "notBarred", "intraFreqReselection": "allowed", "spare": "0" } 2022-07-15T00:18:39.723949 [S1AP ] [I] Rx S1AP SDU - S1SetupResponse 0000: 20 11 00 25 00 00 03 00 3d 40 0a 03 80 73 72 73 0010: 6d 6d 65 30 31 00 69 00 0b 00 00 00 f1 10 00 00 2022-07-15T00:18:39.723957 [S1AP ] [I] Proc "MME Connection" - S1Setup procedure completed successfully 2022-07-15T00:18:39.788757 [RRC-NR ] [I] Number of 5QI 2 2022-07-15T00:18:39.788759 [RRC-NR ] [I] 5QI configuration. 5QI=7 2022-07-15T00:18:39.788772 [RRC-NR ] [I] PDCP NR configuration: { "drb": { "discardTimer": "ms50", "pdcp-SN-SizeUL": "len18bits", "pdcp-SN-SizeDL": "len18bits", "headerCompression": { } }, "t-Reordering": "ms50" } 2022-07-15T00:18:39.788778 [RRC-NR ] [I] RLC NR configuration: { "um-Bi-Directional": { "ul-UM-RLC": { "sn-FieldLength": "size12" }, "dl-UM-RLC": { "sn-FieldLength": "size12", "t-Reassembly": "ms50" } } } 2022-07-15T00:18:39.788780 [RRC-NR ] [I] 5QI configuration. 5QI=9 2022-07-15T00:18:39.788783 [RRC-NR ] [I] PDCP NR configuration: { "drb": { "discardTimer": "ms50", "pdcp-SN-SizeUL": "len18bits", "pdcp-SN-SizeDL": "len18bits", "headerCompression": { } }, "t-Reordering": "ms50" } 2022-07-15T00:18:39.788790 [RRC-NR ] [I] RLC NR configuration: { "am": { "ul-AM-RLC": { "sn-FieldLength": "size12", "t-PollRetransmit": "ms50", "pollPDU": "p4", "pollByte": "kB3000", "maxRetxThreshold": "t4" }, "dl-AM-RLC": { "sn-FieldLength": "size12", "t-Reassembly": "ms50", "t-StatusProhibit": "ms50" } } } 2022-07-15T00:18:39.788792 [RRC-NR ] [I] NIA preference list: NIA0, NIA0, NIA0 2022-07-15T00:18:39.788793 [RRC-NR ] [I] NEA preference list: NEA0, NEA0, NEA0 2022-07-15T00:18:39.790917 [RF ] [I] Configuring physical DL channel 0 with band-pass filter (0.0, 0.0) 2022-07-15T00:18:39.790919 [RF ] [I] Configuring physical UL channel 0 with band-pass filter (0.0, 0.0) 2022-07-15T00:18:39.790922 [RF ] [I] Configuring physical DL channel 1 with band-pass filter (0.0, 0.0) 2022-07-15T00:18:39.790924 [RF ] [I] Configuring physical UL channel 1 with band-pass filter (0.0, 0.0) 2022-07-15T00:18:43.647906 [PHY0 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.647956 [PHY0 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.761285 [PHY1 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.761328 [PHY1 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.873846 [PHY2 ] [I] [ 0] Component Carrier Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.873877 [PHY2 ] [I] [ 0] Worker 0 configured cell 50 PRB 2022-07-15T00:18:43.904930 [PHY-NR ] [I] [ 0] Setting SSB configuration srate=11.52 MHz; c-freq=1842.500 MHz; ss-freq=1839.650 MHz; scs=15kHz; pattern=A; duplex=fdd; period=10 ms; 2022-07-15T00:18:44.008314 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_tx=2680.0 MHz 2022-07-15T00:18:44.108217 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_rx=2560.0 MHz 2022-07-15T00:18:44.281055 [RF ] [I] Mapping RF channel 1 (device=0, channel=1) to logical carrier 1 on f_tx=1842.5 MHz 2022-07-15T00:18:44.306648 [RF ] [I] Mapping RF channel 1 (device=0, channel=1) to logical carrier 1 on f_rx=1747.5 MHz 2022-07-15T00:18:44.461921 [PHY ] [I] [ 0] Starting RX/TX thread nof_prb=50, sf_len=11520 2022-07-15T00:19:04.242733 [RF ] [I] Overflow 2022-07-15T00:19:04.252730 [RF ] [I] Overflow 2022-07-15T00:19:04.252739 [RF ] [I] Overflow 2022-07-15T00:19:04.254542 [RF ] [I] Detected RF gap of -12636.5 us. Sending end-of-burst. 2022-07-15T00:19:04.329383 [RF ] [I] Underflow 2022-07-15T00:19:04.329392 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329396 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329397 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329400 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329403 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329406 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329408 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329411 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329414 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329416 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329418 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329421 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329423 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329426 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329428 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329430 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329437 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329439 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:04.329441 [RF ] [I] Underflow 2022-07-15T00:19:04.329444 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.138722 [RF ] [I] Overflow 2022-07-15T00:19:34.148955 [RF ] [I] Overflow 2022-07-15T00:19:34.148972 [RF ] [I] Overflow 2022-07-15T00:19:34.150720 [RF ] [I] Detected RF gap of -14357.4 us. Sending end-of-burst. 2022-07-15T00:19:34.159621 [RF ] [I] Underflow 2022-07-15T00:19:34.159627 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159630 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159631 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159634 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159636 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159638 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159639 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159641 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159643 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159644 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159647 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159648 [RF ] [I] Late (detected in asynchronous thread) 2022-07-15T00:19:34.159651 [RF ] [I] Late (detected in asynchronous thread)

srsue2.log 2022-07-15T00:21:04.610561 [UE ] [I] Using binary srsue with arguments: 2022-07-15T00:21:04.650129 [UE ] [I] Built in Release mode using 22.04.0. 2022-07-15T00:21:04.709480 [RF ] [I] Configuring physical DL channel 0 with band-pass filter (0.0, 0.0) 2022-07-15T00:21:04.709482 [RF ] [I] Configuring physical UL channel 0 with band-pass filter (0.0, 0.0) 2022-07-15T00:21:04.709483 [RF ] [I] Configuring physical DL channel 1 with band-pass filter (0.0, 0.0) 2022-07-15T00:21:04.709484 [RF ] [I] Configuring physical UL channel 1 with band-pass filter (0.0, 0.0) 2022-07-15T00:21:26.377137 [STCK ] [E] Unknown PCAP option true 2022-07-15T00:21:26.383721 [MAC ] [I] [ 0] Resetting MAC 2022-07-15T00:21:26.383730 [MAC ] [I] [ 0] Logical Channel Setup: LCID=0, LCG=0, priority=0, PBR=-1, BSD=50ms, bucket_size=0 2022-07-15T00:21:26.383733 [MAC ] [I] [ 0] Logical Channel Setup: LCID=1, LCG=0, priority=1, PBR=-1, BSD=50ms, bucket_size=0 2022-07-15T00:21:26.383750 [MAC ] [I] [ 0] Setting configuration 2022-07-15T00:21:26.383752 [MAC ] [I] [ 0] BSR: Configured timer reTX 2560 ms 2022-07-15T00:21:26.383762 [RLC ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode 2022-07-15T00:21:26.383778 [USIM ] [I] Read Home PLMN Id=00101 2022-07-15T00:21:26.384500 [NAS ] [I] Read GUTI from file m_tmsi: ca73497c, mcc: 1, mnc: 1, mme_group_id: 1, mme_code: 1a 2022-07-15T00:21:26.384514 [NAS ] [I] Read security ctxt from file .ctxt. ksi: 0, k_asme: b094b1adf2d826e3fe18aa2be70532df667e7868569a5858c47e81e9bea14469, tx_count: 3, rx_count: 3, int_alg: 1, enc_alg: 0 2022-07-15T00:21:26.384516 [RRC ] [I] Set ue-Identity to 0x26:0x3396553084 2022-07-15T00:21:26.388989 [RLC-NR ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode 2022-07-15T00:21:26.389000 [RRC ] [I] using srand seed of 389000 2022-07-15T00:21:26.835112 [STCK ] [I] Triggering NAS switch on 2022-07-15T00:21:26.835205 [NAS ] [I] Switching on 2022-07-15T00:21:26.931886 [NAS ] [I] No PLMN selected. Starting PLMN Selection... 2022-07-15T00:21:26.931894 [RRC ] [I] Proc "PLMN Search" - Starting PLMN search 2022-07-15T00:21:26.931898 [RRC ] [I] Proc "Cell Search" - Starting... 2022-07-15T00:21:26.931918 [RRC ] [I] FSM "phy_controller" - transition detected - unknown_st -> searching_cell (cause: cell_search_cmd) 2022-07-15T00:21:26.931919 [RRC ] [I] FSM "phy_controller" - Initiating Cell search 2022-07-15T00:21:26.931942 [PHY ] [I] [ 0] INTRA-LTE-0: Disabled neighbour cell search 2022-07-15T00:21:26.931973 [NAS ] [I] Proc "NAS PLMN Search" - Starting... 2022-07-15T00:21:26.932001 [PHY ] [I] [ 0] Resetting PHY... 2022-07-15T00:21:26.932003 [PHY ] [I] [ 0] PHY: Set TA base: n_ta: 0, ta_usec: 0.0 2022-07-15T00:21:26.932016 [PHY ] [I] [ 0] Cell Search: Start EARFCN index=0/1 2022-07-15T00:21:26.932807 [PHY ] [I] [ 0] SYNC: Setting Cell Search sampling rate 2022-07-15T00:21:26.932808 [PHY ] [I] [ 0] Cell Search: changing frequency to EARFCN=3350 2022-07-15T00:21:26.932813 [PHY ] [I] [ 0] SYNC: Set DL EARFCN=3350, f_dl=2680.0 MHz, f_ul=2560.0 MHz 2022-07-15T00:21:26.932823 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_rx=2680.0 MHz 2022-07-15T00:21:27.104699 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_tx=2560.0 MHz 2022-07-15T00:21:27.129422 [PHY ] [I] [ 0] Cell Search: Setting Cell search state 2022-07-15T00:21:27.130397 [PHY ] [I] [ 0] SYNC: Searching for cell... 2022-07-15T00:21:27.250959 [PHY ] [I] [ 0] SYNC: Could not find any cell in this frequency 2022-07-15T00:21:27.250972 [PHY ] [I] [ 0] Cell Search: No cell found in this frequency 2022-07-15T00:21:27.250973 [PHY ] [I] [ 0] Cell Search: No more frequencies in the current EARFCN set 2022-07-15T00:21:27.251032 [RRC ] [W] FSM "phy_controller" - PHY cell search completed. No cells found. 2022-07-15T00:21:27.251044 [RRC ] [I] FSM "phy_controller" - transition detected - searching_cell -> unknown_st (cause: cell_srch_res) 2022-07-15T00:21:27.251594 [RRC ] [I] Proc "PLMN Search" - completed PLMN search 2022-07-15T00:21:27.251595 [RRC ] [I] Proc "PLMN Search" - completed with success 2022-07-15T00:21:27.251597 [NAS ] [W] Proc "NAS PLMN Search" - Did not find any PLMN in the set of frequencies. 2022-07-15T00:21:27.251598 [NAS ] [I] Proc "NAS PLMN Search" - Completed with failure 2022-07-15T00:21:27.251603 [NAS ] [I] No PLMN selected. Starting PLMN Selection... 2022-07-15T00:21:27.251603 [RRC ] [I] Proc "PLMN Search" - Starting PLMN search 2022-07-15T00:21:27.251605 [RRC ] [I] Proc "Cell Search" - Starting... 2022-07-15T00:21:27.251607 [RRC ] [I] FSM "phy_controller" - transition detected - unknown_st -> searching_cell (cause: cell_search_cmd) 2022-07-15T00:21:27.251607 [RRC ] [I] FSM "phy_controller" - Initiating Cell search 2022-07-15T00:21:27.251616 [PHY ] [I] [ 0] INTRA-LTE-0: Disabled neighbour cell search 2022-07-15T00:21:27.251621 [NAS ] [I] Proc "NAS PLMN Search" - Starting... 2022-07-15T00:21:27.251633 [PHY ] [I] [ 0] Resetting PHY... 2022-07-15T00:21:27.251633 [PHY ] [I] [ 0] PHY: Set TA base: n_ta: 0, ta_usec: 0.0 2022-07-15T00:21:27.251638 [PHY ] [I] [ 0] Cell Search: Start EARFCN index=0/1 2022-07-15T00:21:27.251639 [PHY ] [I] [ 0] Cell Search: changing frequency to EARFCN=3350 2022-07-15T00:21:27.251641 [PHY ] [I] [ 0] SYNC: Set DL EARFCN=3350, f_dl=2680.0 MHz, f_ul=2560.0 MHz 2022-07-15T00:21:27.251643 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_rx=2680.0 MHz 2022-07-15T00:21:27.251643 [RF ] [I] RF Rx channel 0 already on freq 2022-07-15T00:21:27.251644 [RF ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_tx=2560.0 MHz 2022-07-15T00:21:27.251644 [RF ] [I] RF Tx channel 0 already on freq 2022-07-15T00:21:27.251648 [PHY ] [I] [ 0] Cell Search: Setting Cell search state 2022-07-15T00:21:27.252581 [PHY ] [I] [ 0] SYNC: Searching for cell... 2022-07-15T00:21:27.373171 [PHY ] [I] [ 0] SYNC: Could not find any cell in this frequency

Steps to reproduce the problem

[Tell us how to reproduce this issue e.g. RF setup, application config files] the zmq config files is provided by the srsran Websites NAS End-to-End the USRP B210 config files only changed srsenb and srsue device_name and device_args .

Additional Information

[Any additional information, configuration or data that might be necessary to reproduce the issue] ue1.log ue2.log enb1.log enb2.log

LongRiver-hash avatar Jul 15 '22 01:07 LongRiver-hash

Firstly, I would recommend that you use either an X310 or N310 USRP. Implementing an NSA connection with two B210s requires modification to the code-base and is not something that we currently support out of the box. The X310 will work as standard, and the N310 requires minor modifications to the config file as outlined here.

Unless you have either of these USRPs available, you should stick with the ZMQ implementation.

Focusing on your ZMQ set-up, it looks to me that from the eNB log the S1 connection is not being established. This means the e/gNB cannot connect to the core. Which in turn will mean your UE will not be able to connect to the network.

I suggest you take a look at why this is happening. Make sure you are using the latest version of srsRAN, and that you first try to get a connection with the config files provided in the application note. Once you have a connection established using the base config, then you can modify the configuration files to meet your needs.

For future reference, issues like this are better suited to the mailing list. GitHub Issues are intended to be used for reporting bugs, or clear issues with the source code.

brendan-mcauliffe avatar Jul 26 '22 10:07 brendan-mcauliffe