[srslte-users] RxErr: Maximum number of transmissions reached (7) SYNC: Sync error. Sending out-of-sync to RRC

Justin Tallon justin.tallon at softwareradiosystems.com
Fri Oct 27 06:38:36 UTC 2017


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 | 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
>
>              0000: 40 10 00 00 00 16
>
> 12:04:53.959464 [MAC ] Info    [04848] SDU:   allocated lcid=0,
> rlc_buffer=6, allocated=6/6, max_sdu_sz=-1, remaining=0
>
> 12:04:53.959476 [MAC ] Info    [04848] UL 4:  New TX for Msg3, RV=0,
> TBS=7, RNTI=180
>
> 12:04:53.959600 [PHY1] Info    [04848] PUSCH: tti_tx=4852, alloc=(2,5),
> tbs=7, mcs=0, rv=0, ack=no, ri=no, cfo=0.1 KHz, tot_time= 254 us
>
> 12:04:53.967464 [PHY1] Info    [04856] PHICH: hi=1, I_lowest=2, n_dmrs=0
>
> 12:04:53.967488 [MAC ] Info    [04856] UL 4:  HARQ = ACK for UL
> transmission. Discarting TB.
>
> 12:04:53.979576 [PHY1] Info    [04868] PDCCH: DL DCI Format1  cce_index=
> 0, L=8, n_data_bits=27, hex=[7f 00 02 20 ]
>
> 12:04:53.979599 [MAC ] Info    [04868] Set NDI=1 for Temp-RNTI DL grant
>
> 12:04:53.979687 [PHY1] Info    [04868] PDSCH: l_crb=14, harq=0, snr=27.7
> dB, TB0: tbs=47, mcs=0, rv=0, crc=OK, it=1, dec_time=  61 us
>
> 12:04:53.979704 [MAC ] Info    [04868] DL 0 (TB 0):  newTX tbs=47, rv=0,
> ack=OK, ndi=1 (0), tti=4868 (0)
>
> 12:04:53.979740 [MAC ] Info    [04868] Delivering PDU for lcid=0, 19 bytes
>
> 12:04:53.979762 [PDCP] Info    RX SRB0 PDU
>
>              0000: 60 12 9b 2e 60 1e 82 b2 65 2a a1 83 4c 09 02 56
>
>              0010: 09 04 20
>
> 12:04:53.979775 [RRC ] Info    TX SRB0 PDU
>
>              0000: 60 12 9b 2e 60 1e 82 b2 65 2a a1 83 4c 09 02 56
>
>              0010: 09 04 20
>
> 12:04:53.979785 [RRC ] Info    TX PDU Stack latency: 25 us
>
> 12:04:53.979790 [PHY1] Info    [04868] PUCCH: tti_tx=4872, n_pucch=2,
> n_prb=0, ack=1, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=408 us
>
> 12:04:53.979799 [RRC ] Info    SRB0 - Received RRC Connection Setup
>
> 12:04:53.979805 [RRC ] Info    Connection Setup received
>
> 12:04:53.979812 [RRC ] Info    Set cqi-PUCCH-ResourceIndex=36,
> cqi-pmi-ConfigIndex=37, cqi-FormatIndicatorPeriodic=wideband_cqi
>
> 12:04:53.979819 [RRC ] Info    Set PHY config ded: SR-n_pucch=36,
> SR-ConfigIndex=16, SR-TransMax=64
>
> 12:04:53.979825 [PHY0] Info    [04868] PHY:   Configuring UL parameters
>
> 12:04:53.979831 [PHY0] Info    [04868] Setting new params worker_id=0,
> pregen_disabled=0
>
> 12:04:53.979839 [PHY1] Info    [04868] Setting new params worker_id=1,
> pregen_disabled=0
>
> 12:04:53.979846 [RRC ] Info    Set MAC main config: harq-MaxReTX=4,
> bsr-TimerReTX=320, bsr-TimerPeriodic=5
>
> 12:04:53.979851 [RRC ] Info    Set MAC PHR config: periodicPHR-Timer=50,
> prohibitPHR-Timer=0, dl-PathlossChange=3
>
> 12:04:53.979857 [PDCP] Info    Added bearer SRB1
>
> 12:04:53.979865 [RLC ] Info    Adding radio bearer SRB1 with mode AM
>
> 12:04:53.979877 [RLC ] Info    SRB1 configured: t_poll_retx=45,
> poll_pdu=-1, poll_byte=-1000, max_retx_thresh=4, t_reordering=35,
> t_status_prohibit=0
>
> 12:04:53.979884 [MAC ] Info    [04868] Logical Channel Setup: LCID=1,
> LCG=0, priority=1, PBR=-1, BSd=-1
>
> 12:04:53.979892 [RRC ] Info    Added radio bearer SRB1
>
> 12:04:53.979897 [RRC ] Info    Notifying NAS of connection setup
>
> 12:04:53.979906 [NAS ] Info    Sending service request
>
> 12:04:53.979927 [RRC ] Info    RX SRB1 SDU
>
>              0000: c7 02 48 26
>
> 12:04:53.979954 [MAC ] Info    [04869] BSR:   Configured timer reTX 320 ms
>
> 12:04:53.979969 [RRC ] Info    Sending RRC Connection Setup Complete
>
> 12:04:53.980100 [MAC ] Info    [04869] PHR:   Configured timer periodic 50
> ms
>
> 12:04:53.980121 [PDCP] Info    TX SRB1 SDU, do_security = false
>
>              0000: 20 00 09 8e 04 90 4c
>
> 12:04:53.980136 [RLC ] Info    SRB1 Tx SDU
>
>              0000: 00 20 00 09 8e 04 90 4c 00 00 00 00
>
> 12:04:53.980144 [MAC ] Info    [04869] RA:    Done:   Random Access
> Complete.     c-rnti=0xb4, ta=6
>
> 12:04:53.986254 [MAC ] Info    [04875] SR:    Signalling PHY sr_counter=1
>
> 12:04:53.987461 [PHY1] Info    [04876] PUCCH: Periodic CQI=14, SNR=28.4 dB
>
> 12:04:53.987560 [PHY1] Info    [04876] PUCCH: tti_tx=4880, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=216 us
>
> 12:04:53.988432 [PHY0] Info    [04877] PUCCH: SR transmission at TTI=4881,
> I_sr=16
>
> 12:04:53.988544 [PHY0] Info    [04877] PUCCH: tti_tx=4881, n_pucch=36,
> n_prb=23, ack=no, ri=no, pmi=no, sr=yes, cfo=0.1 KHz, tot_time=185 us
>
> 12:04:53.996682 [PHY0] Info    [04885] PDCCH: UL DCI Format0  cce_index=8,
> L=4, n_data_bits=25, hex=[06 20 a0 00 ]
>
> 12:04:53.996714 [MAC ] Info    [04885] SDU:   scheduled lcid=1,
> rlc_buffer=14, allocated=14/80
>
> 12:04:53.996723 [MAC ] Info    [04885] Allocating scheduled lch=1 len=-1
>
> 12:04:53.996736 [RLC ] Info    SRB1 Complete SDU scheduled for tx. Stack
> latency: 16778 us
>
> 12:04:53.996744 [RLC ] Info    SRB1 PDU scheduled for tx. SN: 0
>
> 12:04:53.996755 [MAC ] Info    [04885] SDU:   allocated lcid=1,
> rlc_buffer=14, allocated=14/80, max_sdu_sz=-1, remaining=66
>
> 12:04:53.996766 [MAC ] Info    [04885] UL 1:  New TX, RV=0, TBS=85,
> RNTI=180
>
> 12:04:53.996975 [PHY0] Info    [04885] PUSCH: tti_tx=4889, alloc=(0,25),
> tbs=85, mcs=0, rv=0, ack=no, ri=no, cfo=0.0 KHz, tot_time= 539 us
>
> 12:04:54.004383 [PHY0] Info    [04893] PHICH: hi=1, I_lowest=0, n_dmrs=0
>
> 12:04:54.004416 [MAC ] Info    [04893] UL 1:  HARQ = ACK for UL
> transmission. Discarting TB.
>
> 12:04:54.005490 [PHY1] Info    [04894] PDCCH: UL DCI Format0
> cce_index=10, L=2, n_data_bits=25, hex=[06 47 a0 00 ]
>
> 12:04:54.005520 [MAC ] Info    [04894] UL 2:  New TX, RV=0, TBS=41,
> RNTI=180
>
> 12:04:54.005609 [PHY1] Info    [04894] PUSCH: tti_tx=4898, alloc=(0,3),
> tbs=41, mcs=7, rv=0, ack=no, ri=no, cfo=0.0 KHz, tot_time= 289 us
>
> 12:04:54.013457 [PHY1] Info    [04902] PHICH: hi=1, I_lowest=0, n_dmrs=0
>
> 12:04:54.013490 [MAC ] Info    [04902] UL 2:  HARQ = ACK for UL
> transmission. Discarting TB.
>
> 12:04:54.027398 [PHY1] Info    [04916] PUCCH: Periodic CQI=15, SNR=29.9 dB
>
> 12:04:54.027481 [PHY1] Info    [04916] PUCCH: tti_tx=4920, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=166 us
>
> 12:04:54.038217 [PHY0] Info    [04926] PHY:   MABR estimates. DL: 0.680000
> Mbps. UL: 1.096000 Mbps.
>
> 12:04:54.038243 [MAC ] Info    [04927] DL retx: 0.00 %, perpkt: 1.00, UL
> retx: 0.00 % perpkt: 1.00
>
> 12:04:54.038255 [RLC ] Info    LCID=0, RX throughput: 0.000022 Mbps. TX
> throughput: 0.000007 Mbps.
>
> 12:04:54.038263 [RLC ] Info    LCID=1, RX throughput: 0.000000 Mbps. TX
> throughput: 0.000016 Mbps.
>
> 12:04:54.038271 [GW  ] Info    RX throughput: 0.000000 Mbps. TX
> throughput: 0.000096 Mbps.
>
> 12:04:54.067444 [PHY1] Info    [04956] PUCCH: Periodic CQI=14, SNR=28.9 dB
>
> 12:04:54.067541 [PHY1] Info    [04956] PUCCH: tti_tx=4960, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=223 us
>
> 12:04:54.107491 [PHY1] Info    [04996] PUCCH: Periodic CQI=15, SNR=29.8 dB
>
> 12:04:54.107573 [PHY1] Info    [04996] PUCCH: tti_tx=5000, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.2 KHz, tot_time=211 us
>
> 12:04:54.147469 [PHY1] Info    [05036] PUCCH: Periodic CQI=15, SNR=29.5 dB
>
> 12:04:54.147551 [PHY1] Info    [05036] PUCCH: tti_tx=5040, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.2 KHz, tot_time=199 us
>
> 12:04:54.185667 [MAC ] Info    [05075] BSR:   QUEUE status: 0 (0), 0 (0),
> 0 (0), 0 (0), 0 (0), 0 (0),
>
> 12:04:54.187443 [PHY1] Info    [05076] PUCCH: Periodic CQI=15, SNR=29.5 dB
>
> 12:04:54.187525 [PHY1] Info    [05076] PUCCH: tti_tx=5080, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=205 us
>
> 12:04:54.227483 [PHY1] Info    [05116] PUCCH: Periodic CQI=15, SNR=30.0 dB
>
> 12:04:54.227564 [PHY1] Info    [05116] PUCCH: tti_tx=5120, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=212 us
>
> 12:04:54.267497 [PHY1] Info    [05156] PUCCH: Periodic CQI=15, SNR=29.6 dB
>
> 12:04:54.267578 [PHY1] Info    [05156] PUCCH: tti_tx=5160, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=165 us
>
> 12:04:54.307453 [PHY1] Info    [05196] PUCCH: Periodic CQI=15, SNR=29.7 dB
>
> 12:04:54.307535 [PHY1] Info    [05196] PUCCH: tti_tx=5200, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=186 us
>
> 12:04:54.324592 [MAC ] Info    [05214] SR:    Signalling PHY sr_counter=1
>
> 12:04:54.328444 [PHY0] Info    [05217] PUCCH: SR transmission at TTI=5221,
> I_sr=16
>
> 12:04:54.328550 [PHY0] Info    [05217] PUCCH: tti_tx=5221, n_pucch=36,
> n_prb=23, ack=no, ri=no, pmi=no, sr=yes, cfo=0.1 KHz, tot_time=178 us
>
> 12:04:54.336639 [PHY0] Info    [05225] PDCCH: UL DCI Format0  cce_index=8,
> L=4, n_data_bits=25, hex=[25 6f a0 00 ]
>
> 12:04:54.336671 [MAC ] Info    [05225] UL 5:  New TX, RV=0, TBS=533,
> RNTI=180
>
> 12:04:54.336852 [PHY0] Info    [05225] PUSCH: tti_tx=5229, alloc=(0,15),
> tbs=533, mcs=15, rv=0, ack=no, ri=no, cfo=0.1 KHz, tot_time= 477 us
>
> 12:04:54.344488 [PHY0] Info    [05233] PHICH: hi=1, I_lowest=0, n_dmrs=0
>
> 12:04:54.344520 [MAC ] Info    [05233] UL 5:  HARQ = ACK for UL
> transmission. Discarting TB.
>
> 12:04:54.347440 [PHY1] Info    [05236] PUCCH: Periodic CQI=15, SNR=30.2 dB
>
> 12:04:54.347522 [PHY1] Info    [05236] PUCCH: tti_tx=5240, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=166 us
>
> 12:04:54.387444 [PHY1] Info    [05276] PUCCH: Periodic CQI=15, SNR=29.9 dB
>
> 12:04:54.387539 [PHY1] Info    [05276] PUCCH: tti_tx=5280, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=184 us
>
> 12:04:54.427438 [PHY1] Info    [05316] PUCCH: Periodic CQI=15, SNR=29.9 dB
>
> 12:04:54.427519 [PHY1] Info    [05316] PUCCH: tti_tx=5320, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=168 us
>
> 12:04:54.467464 [PHY1] Info    [05356] PUCCH: Periodic CQI=15, SNR=30.0 dB
>
> 12:04:54.467545 [PHY1] Info    [05356] PUCCH: tti_tx=5360, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=182 us
>
> 12:04:54.507413 [PHY1] Info    [05396] PUCCH: Periodic CQI=15, SNR=29.6 dB
>
> 12:04:54.507508 [PHY1] Info    [05396] PUCCH: tti_tx=5400, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.0 KHz, tot_time=181 us
>
> 12:04:54.547414 [PHY1] Info    [05436] PUCCH: Periodic CQI=15, SNR=29.7 dB
>
> 12:04:54.547510 [PHY1] Info    [05436] PUCCH: tti_tx=5440, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=180 us
>
> 12:04:54.587465 [PHY1] Info    [05476] PUCCH: Periodic CQI=15, SNR=30.1 dB
>
> 12:04:54.587560 [PHY1] Info    [05476] PUCCH: tti_tx=5480, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=179 us
>
> 12:04:54.627458 [PHY1] Info    [05516] PUCCH: Periodic CQI=15, SNR=30.0 dB
>
> 12:04:54.627539 [PHY1] Info    [05516] PUCCH: tti_tx=5520, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=173 us
>
> 12:04:54.655887 [MAC ] Info    [05545] SR:    Signalling PHY sr_counter=1
>
> 12:04:54.667468 [PHY1] Info    [05556] PUCCH: Periodic CQI=15, SNR=29.7 dB
>
> 12:04:54.667564 [PHY1] Info    [05556] PUCCH: tti_tx=5560, n_pucch=36,
> n_prb=1, ack=no, ri=no, pmi=no, sr=no, cfo=0.1 KHz, tot_time=201 us
>
> 12:04:54.668417 [PHY0] Info    [05557] PUCCH: SR transmission at TTI=5561,
> I_sr=16
>
> 12:04:54.668524 [PHY0] Info    [05557] PUCCH: tti_tx=5561, n_pucch=36,
> n_prb=23, ack=no, ri=no, pmi=no, sr=yes, cfo=0.1 KHz, tot_time=181 us
>
> 12:04:54.676620 [PHY0] Info    [05565] PDCCH: UL DCI Format0  cce_index=8,
> L=4, n_data_bits=25, hex=[25 6f 20 00 ]
>
> 12:04:54.676650 [MAC ] Info    [05565] UL 1:  New TX, RV=0, TBS=533,
> RNTI=180
>
> 12:04:54.676837 [PHY0] Info   ^C
>
> *diarmuidcire1 at experiment-unit*:*~*$ cat /tmp/ue.log | grep Error
>
> 12:04:37.034597 [USIM] *Error*   Invalid length for IMEI: 14 should be
> 1512:04:37.034637 [USIM] Info    Read Home PLMN Id=20893
>
> 12:04:46.867811 [MAC ] *Error*   [07997] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:46.968711 [PHY0] *Error*   [07996] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:48.267524 [MAC ] *Error*   [09397] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:48.368694 [PHY0] *Error*   [09396] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:48.687501 [MAC ] *Error*   [09817] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:48.788714 [PHY0] *Error*   [09816] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:49.107496 [MAC ] *Error*   [10237] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:49.208697 [PHY0] *Error*   [10236] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:49.527528 [MAC ] *Error*   [00417] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:49.628632 [PHY0] *Error*   [00416] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:49.947490 [MAC ] *Error*   [00837] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:50.048681 [PHY0] *Error*   [00836] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:50.367478 [MAC ] *Error*   [01257] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:50.468692 [PHY0] *Error*   [01256] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:50.787457 [MAC ] *Error*   [01677] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:50.888661 [PHY0] *Error*   [01676] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:51.207483 [MAC ] *Error*   [02097] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:51.308629 [PHY0] *Error*   [02096] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:51.627456 [MAC ] *Error*   [02517] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:51.728669 [PHY0] *Error*   [02516] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:52.047378 [MAC ] *Error*   [02937] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:52.148670 [PHY0] *Error*   [02936] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:52.467446 [MAC ] *Error*   [03357] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:52.568582 [PHY0] *Error*   [03356] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:52.887420 [MAC ] *Error*   [03777] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:52.988678 [PHY0] *Error*   [03776] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:53.307420 [MAC ] *Error*   [04197] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:53.408663 [PHY0] *Error*   [04196] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:53.727432 [MAC ] *Error*   [04617] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:53.828661 [PHY0] *Error*   [04616] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:04:56.827609 [MAC ] *Error*   [07717] RA:    RxErr:  Maximum number of
> transmissions reached (7)
>
> 12:04:56.928560 [PHY0] *Error*   [07716] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> *diarmuidcire1 at experiment-unit*:*~*$ cat /tmp/ue.log | grep Error
>
> 12:07:30.984224 [USIM] *Error*   Invalid length for IMEI: 14 should be
> 1512:07:30.984269 [USIM] Info    Read Home PLMN Id=20893
>
> 12:07:31.528129 [PHY0] *Error*   [02000] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:31.669017 [PHY0] *Error*   [02141] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:31.809016 [PHY0] *Error*   [02281] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:31.949005 [PHY0] *Error*   [02421] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.088979 [PHY0] *Error*   [02561] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.228985 [PHY0] *Error*   [02701] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.369001 [PHY0] *Error*   [02841] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.528990 [PHY0] *Error*   [03001] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.668973 [PHY0] *Error*   [03141] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.808982 [PHY0] *Error*   [03281] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:32.948980 [PHY0] *Error*   [03421] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:33.089016 [PHY0] *Error*   [03561] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:33.229033 [PHY0] *Error*   [03701] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:33.369012 [PHY0] *Error*   [03841] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:33.509003 [PHY0] *Error*   [03981] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> 12:07:33.648980 [PHY0] *Error*   [04121] SYNC:  Sync error. Sending
> out-of-sync to RRC
>
> --
> -------------------------------------------------------------------
> 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/
>
> _______________________________________________
> srslte-users mailing list
> srslte-users at lists.softwareradiosystems.com
> http://www.softwareradiosystems.com/mailman/listinfo/srslte-users
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.srsran.com/pipermail/srsran-users/attachments/20171027/e38d88ce/attachment.htm>


More information about the srsran-users mailing list