[srslte-users] RxErr: Maximum number of transmissions reached (7) SYNC: Sync error. Sending out-of-sync to RRC
Diarmuid Collins
collindi at tcd.ie
Fri Oct 27 10:20:37 UTC 2017
Hi Justin
Apologies for the delay. I had to set up the environment again.
Here you go
Diarmuid
On 27 October 2017 at 08:45, Justin Tallon <
justin.tallon at softwareradiosystems.com> wrote:
> OK, could you perhaps rerun with log level set to debug and send the
> resultant log files?
>
> Thanks!
> Justin
>
> ____
> Justin Tallon Ph.D.
>
> Software Radio Systems (SRS)
> http://www.softwareradiosystems.com
>
> +353-86-067-0753 <086%20067%200753> | justin.tallon@
> softwareradiosystems.com
>
> On Fri, Oct 27, 2017 at 8:41 AM, Diarmuid Collins <collindi at tcd.ie> wrote:
>
>> Yes, I did that but still had the problem
>>
>> On Fri 27 Oct 2017 at 07:39, Justin Tallon <justin.tallon at softwareradiosy
>> stems.com> wrote:
>>
>>> Hey Diarmuid!
>>>
>>> Could you try running the buffer resize commands?
>>>
>>> sudo sysctl -w net.core.rmem_max=33554432
>>>
>>> On both the USRPs you are using, this can sometimes cause problems.
>>>
>>> Cheers,
>>>
>>> Justin
>>>
>>> ____
>>> Justin Tallon Ph.D.
>>>
>>> Software Radio Systems (SRS)
>>> http://www.softwareradiosystems.com
>>>
>>> +353-86-067-0753 <+353%2086%20067%200753> |
>>> justin.tallon at softwareradiosystems.com
>>>
>>> On Thu, Oct 26, 2017 at 3:07 PM, Diarmuid Collins <collindi at tcd.ie>
>>> wrote:
>>>
>>>> Hi Team SRS
>>>>
>>>> I have OpenAir Interface installed on three VMs (HSS, SPGW, MME) and a
>>>> Tx/Rx with two x310s for srsENB and srsUE using srsLTE running on ubuntu
>>>> 16.04.
>>>>
>>>> linux; GNU C++ version 5.4.0 20160609; Boost_105800;
>>>> UHD_003.009.007-0-g50839059
>>>>
>>>> I downloaded and compiled the latest version of srsLTE from
>>>> https://github.com/srsLTE/srsLTE.
>>>>
>>>> When I start all processes (1. hss, 2. mme, 3. spgw, 4. srsenb, 5.
>>>> srsue) the connection sets up and I can ping the SPGW
>>>>
>>>> *diarmuidcire1 at experiment-unit*:*~/enb-conf*$ sudo srsenb enb.conf
>>>>
>>>> linux; GNU C++ version 5.4.0 20160609; Boost_105800;
>>>> UHD_003.009.007-0-g50839059
>>>>
>>>>
>>>> --- Software Radio Systems LTE eNodeB ---
>>>>
>>>>
>>>> Reading configuration file enb.conf...
>>>>
>>>> Opening USRP with args: type=x300,master_clock_rate=184.32e6
>>>>
>>>> -- X300 initialization sequence...
>>>>
>>>> -- Determining maximum frame size... 1472 bytes.
>>>>
>>>> -- Setup basic communication...
>>>>
>>>> -- Loading values from EEPROM...
>>>>
>>>> -- Setup RF frontend clocking...
>>>>
>>>> -- Radio 1x clock:184.32
>>>>
>>>> -- Initialize Radio0 control...
>>>>
>>>> -- Performing register loopback test... pass
>>>>
>>>> -- Initialize Radio1 control...
>>>>
>>>> -- Performing register loopback test... pass
>>>>
>>>>
>>>> UHD Warning:
>>>>
>>>> The recv buffer could not be resized sufficiently.
>>>>
>>>> Target sock buff size: 33554432 bytes.
>>>>
>>>> Actual sock buff size: 212992 bytes.
>>>>
>>>> See the transport application notes on buffer resizing.
>>>>
>>>> Please run: sudo sysctl -w net.core.rmem_max=33554432
>>>>
>>>> Setting frequency: DL=2685.0 Mhz, UL=2565.0 MHz
>>>>
>>>> Setting Sampling frequency 5.76 MHz
>>>>
>>>>
>>>> ==== eNodeB started ===
>>>>
>>>> Type <t> to view trace
>>>>
>>>>
>>>> The UE connects and I get an IP address.
>>>>
>>>> *diarmuidcire1 at experiment-unit*:*~/ue-conf*$ sudo srsue ue.conf
>>>>
>>>> linux; GNU C++ version 5.4.0 20160609; Boost_105800;
>>>> UHD_003.009.007-0-g50839059
>>>>
>>>>
>>>> Reading configuration file ue.conf...
>>>>
>>>> --- Software Radio Systems LTE UE ---
>>>>
>>>>
>>>> Opening RF device with 1 RX antennas...
>>>>
>>>> Opening USRP with args: type=x300,master_clock_rate=184.32e6
>>>>
>>>> -- X300 initialization sequence...
>>>>
>>>> -- Determining maximum frame size... 1472 bytes.
>>>>
>>>> -- Setup basic communication...
>>>>
>>>> -- Loading values from EEPROM...
>>>>
>>>> -- Setup RF frontend clocking...
>>>>
>>>> -- Radio 1x clock:184.32
>>>>
>>>> -- Initialize Radio0 control...
>>>>
>>>> -- Performing register loopback test... pass
>>>>
>>>> -- Initialize Radio1 control...
>>>>
>>>> -- Performing register loopback test... pass
>>>>
>>>>
>>>> UHD Warning:
>>>>
>>>> The recv buffer could not be resized sufficiently.
>>>>
>>>> Target sock buff size: 33554432 bytes.
>>>>
>>>> Actual sock buff size: 212992 bytes.
>>>>
>>>> See the transport application notes on buffer resizing.
>>>>
>>>> Please run: sudo sysctl -w net.core.rmem_max=33554432
>>>>
>>>> Invalid length for IMEI: 14 should be 15Waiting PHY to initialize...
>>>>
>>>> ...
>>>>
>>>> Searching cell in DL EARFCN=3400, f_dl=2685.0 MHz, f_ul=2565.0 MHz
>>>>
>>>> .
>>>>
>>>> Found Cell: PCI=1, PRB=15, Ports=1, CFO=-0.2 KHz
>>>>
>>>> Found PLMN: Id=20893, TAC=1
>>>>
>>>> Select cell: PCI=1, EARFCN=3400, Cell ID=0x19b
>>>>
>>>> Random Access Transmission: seq=1, ra-rnti=0x2
>>>>
>>>> Random Access Complete. c-rnti=0x46, ta=6
>>>>
>>>> RRC Connected
>>>>
>>>> Network attach successful. IP: 172.16.0.2
>>>>
>>>>
>>>> At this point, ping works for several seconds
>>>>
>>>>
>>>> *diarmuidcire1 at experiment-unit*:*~*$ ping -I tun_srsue 172.16.0.1
>>>>
>>>> PING 172.16.0.1 (172.16.0.1) from 172.16.0.2 tun_srsue: 56(84) bytes of
>>>> data.
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=1 ttl=64 time=26.0 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=2 ttl=64 time=13.8 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=3 ttl=64 time=21.9 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=4 ttl=64 time=9.94 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=5 ttl=64 time=18.7 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=6 ttl=64 time=15.7 ms
>>>>
>>>> 64 bytes from 172.16.0.1: icmp_seq=7 ttl=64 time=34.8 ms
>>>>
>>>>
>>>> But then we start to see problems on the UE:
>>>>
>>>> ...
>>>>
>>>> Network attach successful. IP: 172.16.0.2
>>>>
>>>> Scheduling request failed: releasing RRC connection...
>>>>
>>>> Random Access Transmission: seq=1, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=2, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=3, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=4, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=5, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=6, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=7, ra-rnti=0x2
>>>>
>>>> Warning: Detected Radio-Link Failure
>>>>
>>>> RRC Connection Reestablishment
>>>>
>>>> Random Access Transmission: seq=1, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=2, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=3, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=4, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=5, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=1, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=2, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=3, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=4, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=5, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=6, ra-rnti=0x2
>>>>
>>>> Random Access Transmission: seq=7, ra-rnti=0x2
>>>>
>>>> Warning: Detected Radio-Link Failure
>>>>
>>>>
>>>> and on the ENB
>>>>
>>>> ==== eNodeB started ===
>>>>
>>>> Type <t> to view trace
>>>>
>>>> RACH: tti=4021, preamble=1, offset=3, temp_crnti=0x46
>>>>
>>>> User 0x46 connected
>>>>
>>>> RACH: tti=641, preamble=1, offset=0, temp_crnti=0x47
>>>>
>>>> RACH: tti=671, preamble=2, offset=0, temp_crnti=0x48
>>>>
>>>> Disconnecting rnti=0x47.
>>>>
>>>> RACH: tti=701, preamble=3, offset=0, temp_crnti=0x49
>>>>
>>>> RACH: tti=731, preamble=4, offset=0, temp_crnti=0x4a
>>>>
>>>> Disconnecting rnti=0x48.
>>>>
>>>> RACH: tti=761, preamble=5, offset=0, temp_crnti=0x4b
>>>>
>>>> RACH: tti=791, preamble=6, offset=0, temp_crnti=0x4c
>>>>
>>>> Disconnecting rnti=0x49.
>>>>
>>>> RACH: tti=821, preamble=7, offset=0, temp_crnti=0x4d
>>>>
>>>> Disconnecting rnti=0x4a.
>>>>
>>>> Disconnecting rnti=0x4b.
>>>>
>>>> Disconnecting rnti=0x4c.
>>>>
>>>> Disconnecting rnti=0x4d.
>>>>
>>>> RACH: tti=1071, preamble=1, offset=2, temp_crnti=0x4e
>>>>
>>>> RACH: tti=1101, preamble=2, offset=2, temp_crnti=0x4f
>>>>
>>>> Disconnecting rnti=0x4e.
>>>>
>>>> RACH: tti=1131, preamble=3, offset=2, temp_crnti=0x50
>>>>
>>>> RACH: tti=1161, preamble=4, offset=2, temp_crnti=0x51
>>>>
>>>> Disconnecting rnti=0x4f.
>>>>
>>>> RACH: tti=1191, preamble=5, offset=2, temp_crnti=0x52
>>>>
>>>> RACH: tti=1221, preamble=6, offset=2, temp_crnti=0x53
>>>>
>>>> Disconnecting rnti=0x50.
>>>>
>>>> Disconnecting rnti=0x51.
>>>>
>>>> Disconnecting rnti=0x52.
>>>>
>>>> Disconnecting rnti=0x53.
>>>>
>>>> RACH: tti=2031, preamble=1, offset=2, temp_crnti=0x54
>>>>
>>>> RACH: tti=2061, preamble=2, offset=2, temp_crnti=0x55
>>>>
>>>> Disconnecting rnti=0x54.
>>>>
>>>> RACH: tti=2091, preamble=3, offset=2, temp_crnti=0x56
>>>>
>>>> RACH: tti=2121, preamble=4, offset=2, temp_crnti=0x57
>>>>
>>>> Disconnecting rnti=0x55.
>>>>
>>>> RACH: tti=2151, preamble=5, offset=2, temp_crnti=0x58
>>>>
>>>> RACH: tti=2181, preamble=6, offset=2, temp_crnti=0x59
>>>>
>>>> Disconnecting rnti=0x56.
>>>>
>>>> RACH: tti=2211, preamble=7, offset=2, temp_crnti=0x5a
>>>>
>>>> Disconnecting rnti=0x57.
>>>>
>>>> Disconnecting rnti=0x58.
>>>>
>>>> Disconnecting rnti=0x59.
>>>>
>>>> Disconnecting rnti=0x5a.
>>>> ....
>>>>
>>>> I have tried changing with PRB and Gain values - without success as
>>>> suggested by Pedro.
>>>>
>>>> For FYI, I have increased the CPUs on the OAI notes to 2CPUs, and on
>>>> the SRS notes to 6CPUs. I have also changed the PRB value to 15 or 25. I
>>>> have changed the Tx/Rx gain on both UE and endeb to the following values:
>>>> 90/70, 70/50, 60/40, 30/25, 15/15, 15/5. And various other iterations.
>>>>
>>>> The ping works for several seconds but times out and I get the
>>>> following error in the UE log.
>>>>
>>>>
>>>> *diarmuidcire1 at experiment-unit*:*~*$ tail -f /tmp/ue.log | grep Error
>>>>
>>>> 13:09:55.996303 [MAC ] *Error* [06137] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:56.097550 [PHY0] *Error* [06136] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:56.416293 [MAC ] *Error* [06557] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:56.517542 [PHY0] *Error* [06556] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:56.836352 [MAC ] *Error* [06977] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:56.937515 [PHY0] *Error* [06976] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:57.256330 [MAC ] *Error* [07397] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:57.357477 [PHY0] *Error* [07396] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:57.676340 [MAC ] *Error* [07817] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:57.777519 [PHY0] *Error* [07816] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:58.096300 [MAC ] *Error* [08237] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:58.197538 [PHY0] *Error* [08236] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 13:09:58.516314 [MAC ] *Error* [08657] RA: RxErr: Maximum number
>>>> of transmissions reached (7)
>>>>
>>>> 13:09:58.617474 [PHY0] *Error* [08656] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> ^C
>>>>
>>>> *diarmuidcire1 at experiment-unit*:*~*$ ^C
>>>>
>>>>
>>>>
>>>> Please let me know how I might resolve this?
>>>>
>>>> Best regards,
>>>> Diarmuid
>>>>
>>>>
>>>>
>>>> Here are more UE logs
>>>>
>>>>
>>>> 12:04:52.682142 [RRC ] Info Set PUSCH ConfigCommon: HopOffset=2,
>>>> RSGroup=0, RSNcs=0, N_sb=1
>>>>
>>>> 12:04:52.682148 [RRC ] Info Set PUCCH ConfigCommon: DeltaShift=1,
>>>> CyclicShift=0, N1=2, NRB=1
>>>>
>>>> 12:04:52.682166 [RRC ] Info Set PRACH ConfigCommon: SeqIdx=128,
>>>> HS=no, FreqOffset=0, ZC=11, ConfigIndex=3
>>>>
>>>> 12:04:52.682171 [RRC ] Info Set SRS ConfigCommon:
>>>> BW-Configuration=0, SF-Configuration=0, ACKNACK=no
>>>>
>>>> 12:04:52.682177 [RRC ] Info Set Constants and Timers: N310=1,
>>>> N311=1, t301=100, t310=1000, t311=1000
>>>>
>>>> 12:04:52.682452 [RRC ] Info Detected 1 in-sync from PHY. Stopping
>>>> T310 timer
>>>>
>>>> 12:04:52.682514 [MAC ] Info [03572] BSR: QUEUE status: 0 (0), 0
>>>> (0), 0 (0), 0 (0), 0 (0), 0 (0),
>>>>
>>>> 12:04:52.683233 [RRC ] Info RRC Cell Selected: Sending connection
>>>> request...
>>>>
>>>> 12:04:52.683259 [RRC ] Info Sending RRC Connection Request on SRB0
>>>>
>>>> 12:04:52.683267 [PDCP] Info TX SRB0 SDU, do_security = false
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:52.683281 [RLC ] Info SRB0 Tx SDU
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:52.683533 [MAC ] Info [03573] SR: PUCCH not configured.
>>>> Starting RA procedure
>>>>
>>>> 12:04:52.683563 [MAC ] Info [03573] RA: INIT: Starting PRACH by
>>>> MAC order
>>>>
>>>> 12:04:52.688890 [PHY0] Info [03577] PRACH: Transmitted preamble=1,
>>>> CFO=0.05 KHz, tx_time=0.690450
>>>>
>>>> 12:04:52.689164 [MAC ] Info [03578] RA: PDCCH: seq=1,
>>>> ra-rnti=0x2, ra-tti=3581
>>>>
>>>> 12:04:52.718869 [PHY0] Info [03607] PRACH: Transmitted preamble=2,
>>>> CFO=0.03 KHz, tx_time=0.720450
>>>>
>>>> 12:04:52.719068 [MAC ] Info [03608] RA: PDCCH: seq=2,
>>>> ra-rnti=0x2, ra-tti=3611
>>>>
>>>> 12:04:52.748889 [PHY0] Info [03637] PRACH: Transmitted preamble=3,
>>>> CFO=0.01 KHz, tx_time=0.750450
>>>>
>>>> 12:04:52.749090 [MAC ] Info [03638] RA: PDCCH: seq=3,
>>>> ra-rnti=0x2, ra-tti=3641
>>>>
>>>> 12:04:52.778849 [PHY0] Info [03667] PRACH: Transmitted preamble=4,
>>>> CFO=0.01 KHz, tx_time=0.780450
>>>>
>>>> 12:04:52.779051 [MAC ] Info [03668] RA: PDCCH: seq=4,
>>>> ra-rnti=0x2, ra-tti=3671
>>>>
>>>> 12:04:52.808857 [PHY0] Info [03697] PRACH: Transmitted preamble=5,
>>>> CFO=-0.01 KHz, tx_time=0.810450
>>>>
>>>> 12:04:52.809029 [MAC ] Info [03698] RA: PDCCH: seq=5,
>>>> ra-rnti=0x2, ra-tti=3701
>>>>
>>>> 12:04:52.838882 [PHY0] Info [03727] PRACH: Transmitted preamble=6,
>>>> CFO=-0.00 KHz, tx_time=0.840450
>>>>
>>>> 12:04:52.839087 [MAC ] Info [03728] RA: PDCCH: seq=6,
>>>> ra-rnti=0x2, ra-tti=3731
>>>>
>>>> 12:04:52.868885 [PHY0] Info [03757] PRACH: Transmitted preamble=7,
>>>> CFO=0.01 KHz, tx_time=0.870450
>>>>
>>>> 12:04:52.869080 [MAC ] Info [03758] RA: PDCCH: seq=7,
>>>> ra-rnti=0x2, ra-tti=3761
>>>>
>>>> 12:04:52.887420 [MAC ] Error [03777] RA: RxErr: Maximum number of
>>>> transmissions reached (7)
>>>>
>>>> 12:04:52.887449 [PHY0] Warning [03776] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:52.887464 [PHY0] Info [03776] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:52.887508 [PHY0] Info [03776] SYNC: Starting RX streaming
>>>>
>>>> 12:04:52.887644 [PHY0] Info [03776] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:52.887664 [RRC ] Warning Detected Radio-Link Failure
>>>>
>>>> 12:04:52.948537 [RRC ] Info Leaving RRC_CONNECTED state
>>>>
>>>> 12:04:52.948584 [PHY0] Info [03776] Resetting PHY
>>>>
>>>> 12:04:52.948596 [MAC ] Info [03777] Resetting MAC
>>>>
>>>> 12:04:52.950023 [PHY0] Info [03776] PHY: Configuring UL parameters
>>>>
>>>> 12:04:52.950081 [PHY0] Info [03776] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:52.950093 [PHY1] Info [03776] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:52.950102 [RRC ] Info Set MAC main config: harq-MaxReTX=5,
>>>> bsr-TimerReTX=2560, bsr-TimerPeriodic=-1
>>>>
>>>> 12:04:52.950110 [MAC ] Info [03777] SCHED: Searching for DL grant
>>>> for P-RNTI
>>>>
>>>> 12:04:52.951153 [RRC ] Info RRC IDLE: NAS is attached, PHY not
>>>> synchronized. Re-selecting cell...
>>>>
>>>> 12:04:52.951181 [RRC ] Info PLMN Id=20893 selected
>>>>
>>>> 12:04:52.951190 [RRC ] Info Selecting cell PCI=1, EARFCN=3400, Cell
>>>> ID=0x19b
>>>>
>>>> 12:04:52.951226 [PHY0] Info [03776] Cell Select: Already in cell
>>>> EARFCN=3400
>>>>
>>>> 12:04:52.988678 [PHY0] Error [03776] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 12:04:52.988709 [PHY0] Warning [03776] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:52.988724 [PHY0] Info [03776] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:52.988768 [PHY0] Info [03776] SYNC: Starting RX streaming
>>>>
>>>> 12:04:52.988882 [PHY0] Info [03776] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:52.988902 [RRC ] Info Detected 1 out-of-sync from PHY.
>>>> Starting T310 timer
>>>>
>>>> 12:04:53.101369 [PHY0] Info [03776] SYNC: Trying to decode MIB...
>>>> SNR=36.9 dB
>>>>
>>>> 12:04:53.101609 [PHY0] Info [03776] SYNC: DONE, TTI=3990,
>>>> sfn_offset=3
>>>>
>>>> 12:04:53.101631 [PHY0] Info [03776] Sync OK. Camping on cell PCI=1...
>>>>
>>>> 12:04:53.102501 [RRC ] Info Detected 1 in-sync from PHY. Stopping
>>>> T310 timer
>>>>
>>>> 12:04:53.102543 [RRC ] Info Set RACH ConfigCommon: NofPreambles=52,
>>>> ResponseWindow=10, ContentionResolutionTimer=64 ms
>>>>
>>>> 12:04:53.102554 [PHY0] Info [03991] PHY: Configuring UL parameters
>>>>
>>>> 12:04:53.102562 [PHY0] Info [03991] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.102569 [PHY1] Info [03776] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.102576 [RRC ] Info Set PUSCH ConfigCommon: HopOffset=2,
>>>> RSGroup=0, RSNcs=0, N_sb=1
>>>>
>>>> 12:04:53.102582 [RRC ] Info Set PUCCH ConfigCommon: DeltaShift=1,
>>>> CyclicShift=0, N1=2, NRB=1
>>>>
>>>> 12:04:53.102588 [RRC ] Info Set PRACH ConfigCommon: SeqIdx=128,
>>>> HS=no, FreqOffset=0, ZC=11, ConfigIndex=3
>>>>
>>>> 12:04:53.102593 [RRC ] Info Set SRS ConfigCommon:
>>>> BW-Configuration=0, SF-Configuration=0, ACKNACK=no
>>>>
>>>> 12:04:53.102598 [RRC ] Info Set Constants and Timers: N310=1,
>>>> N311=1, t301=100, t310=1000, t311=1000
>>>>
>>>> 12:04:53.103643 [RRC ] Info RRC Cell Selected: Sending connection
>>>> request...
>>>>
>>>> 12:04:53.103669 [RRC ] Info Sending RRC Connection Request on SRB0
>>>>
>>>> 12:04:53.103679 [PDCP] Info TX SRB0 SDU, do_security = false
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.103692 [RLC ] Info SRB0 Tx SDU
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.104482 [MAC ] Info [03994] SR: PUCCH not configured.
>>>> Starting RA procedure
>>>>
>>>> 12:04:53.104512 [MAC ] Info [03994] RA: INIT: Starting PRACH by
>>>> MAC order
>>>>
>>>> 12:04:53.108964 [PHY0] Info [03997] PRACH: Transmitted preamble=1,
>>>> CFO=-0.02 KHz, tx_time=0.110450
>>>>
>>>> 12:04:53.109262 [MAC ] Info [03998] RA: PDCCH: seq=1,
>>>> ra-rnti=0x2, ra-tti=4001
>>>>
>>>> 12:04:53.138848 [PHY0] Info [04027] PRACH: Transmitted preamble=2,
>>>> CFO=-0.02 KHz, tx_time=0.140450
>>>>
>>>> 12:04:53.139051 [MAC ] Info [04028] RA: PDCCH: seq=2,
>>>> ra-rnti=0x2, ra-tti=4031
>>>>
>>>> 12:04:53.168842 [PHY0] Info [04057] PRACH: Transmitted preamble=3,
>>>> CFO=-0.01 KHz, tx_time=0.170450
>>>>
>>>> 12:04:53.169043 [MAC ] Info [04058] RA: PDCCH: seq=3,
>>>> ra-rnti=0x2, ra-tti=4061
>>>>
>>>> 12:04:53.183439 [MAC ] Info [04073] BSR: QUEUE status: 6 (6), 0
>>>> (0), 0 (0), 0 (0), 0 (0), 0 (0),
>>>>
>>>> 12:04:53.198885 [PHY0] Info [04087] PRACH: Transmitted preamble=4,
>>>> CFO=-0.02 KHz, tx_time=0.200450
>>>>
>>>> 12:04:53.199071 [MAC ] Info [04088] RA: PDCCH: seq=4,
>>>> ra-rnti=0x2, ra-tti=4091
>>>>
>>>> 12:04:53.228880 [PHY0] Info [04117] PRACH: Transmitted preamble=5,
>>>> CFO=-0.01 KHz, tx_time=0.230450
>>>>
>>>> 12:04:53.229056 [MAC ] Info [04118] RA: PDCCH: seq=5,
>>>> ra-rnti=0x2, ra-tti=4121
>>>>
>>>> 12:04:53.258856 [PHY0] Info [04147] PRACH: Transmitted preamble=6,
>>>> CFO=-0.01 KHz, tx_time=0.260450
>>>>
>>>> 12:04:53.259034 [MAC ] Info [04148] RA: PDCCH: seq=6,
>>>> ra-rnti=0x2, ra-tti=4151
>>>>
>>>> 12:04:53.288867 [PHY0] Info [04177] PRACH: Transmitted preamble=7,
>>>> CFO=-0.00 KHz, tx_time=0.290450
>>>>
>>>> 12:04:53.289041 [MAC ] Info [04178] RA: PDCCH: seq=7,
>>>> ra-rnti=0x2, ra-tti=4181
>>>>
>>>> 12:04:53.307420 [MAC ] Error [04197] RA: RxErr: Maximum number of
>>>> transmissions reached (7)
>>>>
>>>> 12:04:53.307447 [PHY0] Warning [04196] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:53.307467 [PHY0] Info [04196] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:53.307510 [PHY0] Info [04196] SYNC: Starting RX streaming
>>>>
>>>> 12:04:53.307680 [PHY0] Info [04196] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:53.307702 [RRC ] Warning Detected Radio-Link Failure
>>>>
>>>> 12:04:53.367988 [RRC ] Info Leaving RRC_CONNECTED state
>>>>
>>>> 12:04:53.368019 [PHY0] Info [04196] Resetting PHY
>>>>
>>>> 12:04:53.368029 [MAC ] Info [04197] Resetting MAC
>>>>
>>>> 12:04:53.369600 [PHY0] Info [04196] PHY: Configuring UL parameters
>>>>
>>>> 12:04:53.369619 [PHY0] Info [04196] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.369627 [PHY1] Info [04196] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.369635 [RRC ] Info Set MAC main config: harq-MaxReTX=5,
>>>> bsr-TimerReTX=2560, bsr-TimerPeriodic=-1
>>>>
>>>> 12:04:53.369642 [MAC ] Info [04197] SCHED: Searching for DL grant
>>>> for P-RNTI
>>>>
>>>> 12:04:53.370690 [RRC ] Info RRC IDLE: NAS is attached, PHY not
>>>> synchronized. Re-selecting cell...
>>>>
>>>> 12:04:53.370713 [RRC ] Info PLMN Id=20893 selected
>>>>
>>>> 12:04:53.370720 [RRC ] Info Selecting cell PCI=1, EARFCN=3400, Cell
>>>> ID=0x19b
>>>>
>>>> 12:04:53.370744 [PHY0] Info [04196] Cell Select: Already in cell
>>>> EARFCN=3400
>>>>
>>>> 12:04:53.408663 [PHY0] Error [04196] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 12:04:53.408695 [PHY0] Warning [04196] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:53.408709 [PHY0] Info [04196] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:53.408749 [PHY0] Info [04196] SYNC: Starting RX streaming
>>>>
>>>> 12:04:53.408862 [PHY0] Info [04196] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:53.408881 [RRC ] Info Detected 1 out-of-sync from PHY.
>>>> Starting T310 timer
>>>>
>>>> 12:04:53.521346 [PHY0] Info [04196] SYNC: Trying to decode MIB...
>>>> SNR=35.7 dB
>>>>
>>>> 12:04:53.521520 [PHY0] Info [04196] SYNC: DONE, TTI=4410,
>>>> sfn_offset=1
>>>>
>>>> 12:04:53.521541 [PHY0] Info [04196] Sync OK. Camping on cell PCI=1...
>>>>
>>>> 12:04:53.522401 [RRC ] Info Set RACH ConfigCommon: NofPreambles=52,
>>>> ResponseWindow=10, ContentionResolutionTimer=64 ms
>>>>
>>>> 12:04:53.522430 [PHY0] Info [04411] PHY: Configuring UL parameters
>>>>
>>>> 12:04:53.522440 [PHY0] Info [04411] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.522448 [PHY1] Info [04196] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.522454 [RRC ] Info Set PUSCH ConfigCommon: HopOffset=2,
>>>> RSGroup=0, RSNcs=0, N_sb=1
>>>>
>>>> 12:04:53.522460 [RRC ] Info Set PUCCH ConfigCommon: DeltaShift=1,
>>>> CyclicShift=0, N1=2, NRB=1
>>>>
>>>> 12:04:53.522470 [RRC ] Info Set PRACH ConfigCommon: SeqIdx=128,
>>>> HS=no, FreqOffset=0, ZC=11, ConfigIndex=3
>>>>
>>>> 12:04:53.522474 [RRC ] Info Detected 1 in-sync from PHY. Stopping
>>>> T310 timer
>>>>
>>>> 12:04:53.522476 [RRC ] Info Set SRS ConfigCommon:
>>>> BW-Configuration=0, SF-Configuration=0, ACKNACK=no
>>>>
>>>> 12:04:53.522497 [RRC ] Info Set Constants and Timers: N310=1,
>>>> N311=1, t301=100, t310=1000, t311=1000
>>>>
>>>> 12:04:53.523569 [RRC ] Info RRC Cell Selected: Sending connection
>>>> request...
>>>>
>>>> 12:04:53.523595 [RRC ] Info Sending RRC Connection Request on SRB0
>>>>
>>>> 12:04:53.523605 [PDCP] Info TX SRB0 SDU, do_security = false
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.523617 [RLC ] Info SRB0 Tx SDU
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.524483 [MAC ] Info [04414] SR: PUCCH not configured.
>>>> Starting RA procedure
>>>>
>>>> 12:04:53.524508 [MAC ] Info [04414] RA: INIT: Starting PRACH by
>>>> MAC order
>>>>
>>>> 12:04:53.528943 [PHY0] Info [04417] PRACH: Transmitted preamble=1,
>>>> CFO=-0.00 KHz, tx_time=0.530450
>>>>
>>>> 12:04:53.529196 [MAC ] Info [04418] RA: PDCCH: seq=1,
>>>> ra-rnti=0x2, ra-tti=4421
>>>>
>>>> 12:04:53.558902 [PHY0] Info [04447] PRACH: Transmitted preamble=2,
>>>> CFO=0.03 KHz, tx_time=0.560450
>>>>
>>>> 12:04:53.559080 [MAC ] Info [04448] RA: PDCCH: seq=2,
>>>> ra-rnti=0x2, ra-tti=4451
>>>>
>>>> 12:04:53.588847 [PHY0] Info [04477] PRACH: Transmitted preamble=3,
>>>> CFO=0.02 KHz, tx_time=0.590450
>>>>
>>>> 12:04:53.589020 [MAC ] Info [04478] RA: PDCCH: seq=3,
>>>> ra-rnti=0x2, ra-tti=4481
>>>>
>>>> 12:04:53.618866 [PHY0] Info [04507] PRACH: Transmitted preamble=4,
>>>> CFO=0.00 KHz, tx_time=0.620450
>>>>
>>>> 12:04:53.619040 [MAC ] Info [04508] RA: PDCCH: seq=4,
>>>> ra-rnti=0x2, ra-tti=4511
>>>>
>>>> 12:04:53.648864 [PHY0] Info [04537] PRACH: Transmitted preamble=5,
>>>> CFO=0.00 KHz, tx_time=0.650450
>>>>
>>>> 12:04:53.649036 [MAC ] Info [04538] RA: PDCCH: seq=5,
>>>> ra-rnti=0x2, ra-tti=4541
>>>>
>>>> 12:04:53.678828 [PHY0] Info [04567] PRACH: Transmitted preamble=6,
>>>> CFO=0.00 KHz, tx_time=0.680450
>>>>
>>>> 12:04:53.679029 [MAC ] Info [04568] RA: PDCCH: seq=6,
>>>> ra-rnti=0x2, ra-tti=4571
>>>>
>>>> 12:04:53.684384 [MAC ] Info [04574] BSR: QUEUE status: 6 (6), 0
>>>> (0), 0 (0), 0 (0), 0 (0), 0 (0),
>>>>
>>>> 12:04:53.708853 [PHY0] Info [04597] PRACH: Transmitted preamble=7,
>>>> CFO=-0.00 KHz, tx_time=0.710450
>>>>
>>>> 12:04:53.709056 [MAC ] Info [04598] RA: PDCCH: seq=7,
>>>> ra-rnti=0x2, ra-tti=4601
>>>>
>>>> 12:04:53.727432 [MAC ] Error [04617] RA: RxErr: Maximum number of
>>>> transmissions reached (7)
>>>>
>>>> 12:04:53.727463 [PHY0] Warning [04616] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:53.727493 [PHY0] Info [04616] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:53.727550 [PHY0] Info [04616] SYNC: Starting RX streaming
>>>>
>>>> 12:04:53.727676 [PHY0] Info [04616] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:53.727696 [RRC ] Warning Detected Radio-Link Failure
>>>>
>>>> 12:04:53.788460 [RRC ] Info Leaving RRC_CONNECTED state
>>>>
>>>> 12:04:53.788490 [PHY0] Info [04616] Resetting PHY
>>>>
>>>> 12:04:53.788500 [MAC ] Info [04617] Resetting MAC
>>>>
>>>> 12:04:53.790159 [PHY0] Info [04616] PHY: Configuring UL parameters
>>>>
>>>> 12:04:53.790208 [PHY0] Info [04616] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.790220 [PHY1] Info [04616] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.790228 [RRC ] Info Set MAC main config: harq-MaxReTX=5,
>>>> bsr-TimerReTX=2560, bsr-TimerPeriodic=-1
>>>>
>>>> 12:04:53.790235 [MAC ] Info [04617] SCHED: Searching for DL grant
>>>> for P-RNTI
>>>>
>>>> 12:04:53.791284 [RRC ] Info RRC IDLE: NAS is attached, PHY not
>>>> synchronized. Re-selecting cell...
>>>>
>>>> 12:04:53.791311 [RRC ] Info PLMN Id=20893 selected
>>>>
>>>> 12:04:53.791334 [RRC ] Info Selecting cell PCI=1, EARFCN=3400, Cell
>>>> ID=0x19b
>>>>
>>>> 12:04:53.791356 [PHY0] Info [04616] Cell Select: Already in cell
>>>> EARFCN=3400
>>>>
>>>> 12:04:53.828661 [PHY0] Error [04616] SYNC: Sync error. Sending
>>>> out-of-sync to RRC
>>>>
>>>> 12:04:53.828691 [PHY0] Warning [04616] SYNC: Resetting sync,
>>>> cell_search_in_progress=no
>>>>
>>>> 12:04:53.828706 [PHY0] Info [04616] SYNC: Stopping RX streaming
>>>>
>>>> 12:04:53.828761 [PHY0] Info [04616] SYNC: Starting RX streaming
>>>>
>>>> 12:04:53.828911 [PHY0] Info [04616] SYNC: Starting SFN
>>>> synchronization
>>>>
>>>> 12:04:53.828933 [RRC ] Info Detected 1 out-of-sync from PHY.
>>>> Starting T310 timer
>>>>
>>>> 12:04:53.941383 [PHY0] Info [04616] SYNC: Trying to decode MIB...
>>>> SNR=40.1 dB
>>>>
>>>> 12:04:53.941655 [PHY0] Info [04616] SYNC: DONE, TTI=4830,
>>>> sfn_offset=3
>>>>
>>>> 12:04:53.941676 [PHY0] Info [04616] Sync OK. Camping on cell PCI=1...
>>>>
>>>> 12:04:53.941980 [RRC ] Info Set RACH ConfigCommon: NofPreambles=52,
>>>> ResponseWindow=10, ContentionResolutionTimer=64 ms
>>>>
>>>> 12:04:53.942008 [PHY0] Info [04616] PHY: Configuring UL parameters
>>>>
>>>> 12:04:53.942018 [PHY0] Info [04616] Setting new params worker_id=0,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.942025 [PHY1] Info [04616] Setting new params worker_id=1,
>>>> pregen_disabled=0
>>>>
>>>> 12:04:53.942032 [RRC ] Info Set PUSCH ConfigCommon: HopOffset=2,
>>>> RSGroup=0, RSNcs=0, N_sb=1
>>>>
>>>> 12:04:53.942038 [RRC ] Info Set PUCCH ConfigCommon: DeltaShift=1,
>>>> CyclicShift=0, N1=2, NRB=1
>>>>
>>>> 12:04:53.942078 [RRC ] Info Set PRACH ConfigCommon: SeqIdx=128,
>>>> HS=no, FreqOffset=0, ZC=11, ConfigIndex=3
>>>>
>>>> 12:04:53.942091 [RRC ] Info Set SRS ConfigCommon:
>>>> BW-Configuration=0, SF-Configuration=0, ACKNACK=no
>>>>
>>>> 12:04:53.942101 [RRC ] Info Set Constants and Timers: N310=1,
>>>> N311=1, t301=100, t310=1000, t311=1000
>>>>
>>>> 12:04:53.942429 [RRC ] Info Detected 1 in-sync from PHY. Stopping
>>>> T310 timer
>>>>
>>>> 12:04:53.943148 [RRC ] Info RRC Cell Selected: Sending connection
>>>> request...
>>>>
>>>> 12:04:53.943180 [RRC ] Info Sending RRC Connection Request on SRB0
>>>>
>>>> 12:04:53.943190 [PDCP] Info TX SRB0 SDU, do_security = false
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.943204 [RLC ] Info SRB0 Tx SDU
>>>>
>>>> 0000: 40 10 00 00 00 16
>>>>
>>>> 12:04:53.943479 [MAC ] Info [04833] SR: PUCCH not configured.
>>>> Starting RA procedure
>>>>
>>>> 12:04:53.943510 [MAC ] Info [04833] RA: INIT: Starting PRACH by
>>>> MAC order
>>>>
>>>> 12:04:53.949088 [PHY0] Info [04837] PRACH: Transmitted preamble=1,
>>>> CFO=0.04 KHz, tx_time=0.950450
>>>>
>>>> 12:04:53.949452 [MAC ] Info [04839] RA: PDCCH: seq=1,
>>>> ra-rnti=0x2, ra-tti=4841
>>>>
>>>> 12:04:53.957478 [PHY1] Info [04846] PDCCH: DL DCI Format1A
>>>> cce_index= 0, L=8, n_data_bits=25, hex=[86 40 01 00 ]
>>>>
>>>> 12:04:53.957568 [PHY1] Info [04846] PDSCH: l_crb= 3, harq=0,
>>>> snr=30.3 dB, TB0: tbs=7, mcs=0, rv=0, crc=OK, it=1, dec_time= 35 us
>>>>
>>>> 12:04:53.957601 [PHY0] Info [04846] PHY: Set TA RAR: ta_cmd: 6,
>>>> n_ta: 96, ta_usec: 3.1
>>>>
>>>> 12:04:53.957611 [MAC ] Info [04846] RA: Rx: RAPID=1, TA=6
>>>>
>>>> 12:04:53.959429 [RLC ] Info SRB0 Complete SDU scheduled for tx.
>>>> Stack latency: 16246 us
>>>>
>>>> 12:04:53.959451 [RLC ] Info TX SRB0, Transparent Mode PDU
>>>>
>>>> --
>> -------------------------------------------------------------------
>> Diarmuid Collins PhD
>> CONNECT Centre for Future Networks
>> Dunlop Oriel House
>> Trinity College
>> Dublin 2, Ireland
>> M: 085 143 8024
>> E: collindi at tcd.ie
>> W:http://www.scss.tcd.ie/~collindi/
>>
>
>
--
-------------------------------------------------------------------
Diarmuid Collins PhD
CONNECT Centre for Future Networks
Dunlop Oriel House
Trinity College
Dublin 2, Ireland
M: 085 143 8024
E: collindi at tcd.ie
W:http://www.scss.tcd.ie/~collindi/
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20171027/21d02cf0/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: enb.log.zip
Type: application/zip
Size: 993104 bytes
Desc: not available
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20171027/21d02cf0/attachment.zip>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ue.log.zip
Type: application/zip
Size: 653119 bytes
Desc: not available
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20171027/21d02cf0/attachment-0001.zip>
More information about the srsran-users
mailing list