Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

bladeRF with FPGA version 0.11.1 does not work with howto example #688

Closed
chuckixia opened this issue Jun 23, 2021 · 8 comments
Closed

bladeRF with FPGA version 0.11.1 does not work with howto example #688

chuckixia opened this issue Jun 23, 2021 · 8 comments

Comments

@chuckixia
Copy link

chuckixia commented Jun 23, 2021 •
edited
Loading

Issue Description

srs UE attach appears to fail when frequency changes

root@host:~# srsue
Reading configuration file /root/.config/srsran/ue.conf...
WARNING: Could not verify cpu0 scaling governor
WARNING: Could not verify cpu1 scaling governor
WARNING: Could not verify cpu2 scaling governor
WARNING: Could not verify cpu3 scaling governor

Built in Release mode using commit 89f16eed2 on branch master.

Opening 1 channels in RF device=default with args=default
Opening bladeRF...
Set RX sampling rate 1.92 Mhz, filter BW: 2.50 Mhz
Waiting PHY to initialize ... done!
Attaching UE...
Set RX sampling rate 1.92 Mhz, filter BW: 2.50 Mhz
set RX frequency to 2680000001
set TX frequency to 2560000001
.
Found Cell:  Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.3 KHz
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Found PLMN:  Id=00101, TAC=7
RF status: O=84, U=0, L=0
Set RX sampling rate 1.92 Mhz, filter BW: 2.50 Mhz
.
Found Cell:  Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.6 KHz

Setup Details

  • Two bladeRF's x115, about a foot apart from each other
  • FPGA version 0.11.1
  • firmware 2.4.0
  • calibrated

Expected Behavior

srsUE should attached

Steps to reproduce the problem

follow the tutorial example here
https://docs.srsran.com/en/latest/usermanuals/source/1_setup.html#running-a-4g-end-to-end-system

Additional Information

installing firmware v0.12.0 appears to produce this problem - Nuand/bladeRF#819
And firmware 0.11.1 might be this problem Nuand/bladeRF#778

so I'm trying to figure out if there is a way around this one way or the other. thanks.
@andrepuschmann
Copy link
Collaborator

Hey, yeah, it's a known problem, see Nuand/bladeRF#778 for example. I assume the eNB works well with your current setup. One thing you can try on the UE is to fix the sample rate at the radio and let srsUE do the downsampling if needed. Try:

[rf]
srate = 11.52e6

For example.

@chuckixia
Copy link
Author

it's hard to know since I'm just trying out from the getting started guide and only have two bladeRF's. But yes, it appears that the eNB is working fine. If you've got a way for me to independently verify that with a smart phone, let me know :).

@chuckixia
Copy link
Author

ok that got a lot farther.

UE

Reading configuration file /root/.config/srsran/ue.conf...
WARNING: Could not verify cpu0 scaling governor
WARNING: Could not verify cpu1 scaling governor
WARNING: Could not verify cpu2 scaling governor
WARNING: Could not verify cpu3 scaling governor

Built in Release mode using commit 89f16eed2 on branch master.

Opening 1 channels in RF device=default with args=default
Opening bladeRF...
Set RX sampling rate 1.92 Mhz, filter BW: 2.50 Mhz
Waiting PHY to initialize ... done!
Attaching UE...
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
set RX frequency to 2680000001
set TX frequency to 2560000001
.
Found Cell:  Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.5 KHz
Found PLMN:  Id=00101, TAC=7
Random Access Transmission: seq=33, tti=6581, ra-rnti=0x2
Random Access Transmission: seq=2, tti=6601, ra-rnti=0x2
Random Access Transmission: seq=32, tti=6621, ra-rnti=0x2
Random Access Transmission: seq=17, tti=6641, ra-rnti=0x2
Random Access Transmission: seq=20, tti=6661, ra-rnti=0x2
RF status: O=338, U=0, L=1
/home/nobletrout/github/srsRAN/lib/src/phy/rf/rf_blade_imp.c.532: TX failed: Invalid operation or parameter
Random Access Transmission: seq=34, tti=6681, ra-rnti=0x2
Random Access Transmission: seq=10, tti=6701, ra-rnti=0x2
Random Access Transmission: seq=28, tti=6721, ra-rnti=0x2
/home/nobletrout/github/srsRAN/lib/src/phy/rf/rf_blade_imp.c.532: TX failed: Invalid operation or parameter
Random Access Transmission: seq=42, tti=6741, ra-rnti=0x2
Random Access Transmission: seq=42, tti=6761, ra-rnti=0x2
RF status: O=1055, U=0, L=1
RF status: O=750, U=0, L=0
RF status: O=448, U=0, L=0
RF status: O=611, U=0, L=0
RF status: O=181, U=0, L=0
RF status: O=451, U=0, L=0
RF status: O=479, U=0, L=0
RF status: O=663, U=0, L=0
RF status: O=629, U=0, L=0
RF status: O=290, U=0, L=0

enb

root@racoon:~# srsenb
---  Software Radio Systems LTE eNodeB  ---

Reading configuration file /root/.config/srsran/enb.conf...
WARNING: cpu0 scaling governor is not set to performance mode. Realtime processing could be compromised. Consider setting it to performance mode before running the application.

Built in Release mode using commit 89f16eed2 on branch master.

Opening 1 channels in RF device=default with args=default
Opening bladeRF...
Set RX sampling rate 1.92 Mhz, filter BW: 2.50 Mhz
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Setting frequency: DL=2680.0 Mhz, UL=2560.0 MHz for cc_idx=0 nof_prb=50
set TX frequency to 2680000001
set RX frequency to 2560000001

==== eNodeB started ===
Type <t> to view trace
RACH:  tti=6631, cc=0, preamble=40, offset=29, temp_crnti=0x46
Disconnecting rnti=0x46.

@chuckixia
Copy link
Author

chuckixia commented Jun 23, 2021 •
edited
Loading

I've managed to get MAC and sometimes NAS messages sent/received, but it still appears to be having some kind of issue. I've done the following to get the bladeRF's past the firmware issue, but believe I now either have a timing or synch issue, which I'm struggling to find a solution for.

here is the diff from git

diff --git a/lib/src/phy/rf/rf_blade_imp.c b/lib/src/phy/rf/rf_blade_imp.c
index b5160ba1b..64c899d67 100644
--- a/lib/src/phy/rf/rf_blade_imp.c
+++ b/lib/src/phy/rf/rf_blade_imp.c
@@ -220,8 +220,11 @@ int rf_blade_open(char* args, void** h)
   handler->tx_stream_enabled = false;

   /* Set default sampling rates */
-  rf_blade_set_tx_srate(handler, 1.92e6);
-  rf_blade_set_rx_srate(handler, 1.92e6);
+
+  rf_blade_set_rx_srate(handler, 11.52e6);
+  rf_blade_set_tx_srate(handler, 11.52e6);
+  //rf_blade_set_rx_srate(handler, 1.92e6);
+  //rf_blade_set_rx_srate(handler, 1.92e6);

   /* Set info structure */
   handler->info.min_tx_gain = range_tx->min;

the calling options from srsenb

srsenb --expert.max_prach_offset_us=180 --rf.time_adv_nsamples=1900

the calling options and config from srsue

srsue --rf.time_adv_nsamples=200 --phy.prach_gain=-1
[rf]
freq_offset = 0
tx_gain = 80
rx_gain = 40
srate = 11.52e6

ue output

Reading configuration file /root/.config/srsran/ue.conf...
WARNING: Could not verify cpu0 scaling governor
WARNING: Could not verify cpu1 scaling governor
WARNING: Could not verify cpu2 scaling governor
WARNING: Could not verify cpu3 scaling governor

Built in Release mode using commit 89f16eed2 on branch master.

Opening 1 channels in RF device=default with args=default
Opening bladeRF...
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Waiting PHY to initialize ... done!
Attaching UE...
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Setting manual TX/RX offset to 200 samples
set RX frequency to 2680000001
set TX frequency to 2560000001
.
Found Cell:  Mode=FDD, PCI=1, PRB=50, Ports=1, CFO=0.6 KHz
Setting manual TX/RX offset to 200 samples
Found PLMN:  Id=00101, TAC=7
Random Access Transmission: seq=2, tti=2901, ra-rnti=0x2
Random Access Transmission: seq=46, tti=2921, ra-rnti=0x2
Random Access Transmission: seq=20, tti=2941, ra-rnti=0x2
Random Access Transmission: seq=4, tti=2961, ra-rnti=0x2
Random Access Transmission: seq=7, tti=2981, ra-rnti=0x2
Random Access Transmission: seq=44, tti=3001, ra-rnti=0x2
Random Access Transmission: seq=19, tti=3021, ra-rnti=0x2
Random Access Transmission: seq=33, tti=3041, ra-rnti=0x2
Random Access Transmission: seq=15, tti=3061, ra-rnti=0x2
Random Access Transmission: seq=31, tti=3081, ra-rnti=0x2
RF status: O=605, U=0, L=0
RF status: O=936, U=0, L=0
RF status: O=101, U=0, L=0
RF status: O=283, U=0, L=0
RF status: O=442, U=0, L=0
^CStopping ..
Random Access Transmission: seq=3, tti=8541, ra-rnti=0x2
Random Access Transmission: seq=41, tti=8561, ra-rnti=0x2
Random Access Transmission: seq=4, tti=8581, ra-rnti=0x2
Random Access Transmission: seq=36, tti=8601, ra-rnti=0x2
Saving MAC PCAP (DLT=149) to /tmp/ue.pcap
Saving NAS PCAP file (DLT=148) to /tmp/ue_nas.pcap
---  exiting  ---

srsenb output

---  Software Radio Systems LTE eNodeB  ---

Reading configuration file /root/.config/srsran/enb.conf...
WARNING: cpu0 scaling governor is not set to performance mode. Realtime processing could be compromised. Consider setting it to performance mode before running the application.

Built in Release mode using commit 89f16eed2 on branch master.

Opening 1 channels in RF device=bladeRF with args=default
Opening bladeRF...
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Set RX sampling rate 11.52 Mhz, filter BW: 10.00 Mhz
Setting manual TX/RX offset to 200 samples
Setting frequency: DL=2680.0 Mhz, UL=2560.0 MHz for cc_idx=0 nof_prb=50
set TX frequency to 2680000001
set RX frequency to 2560000001

==== eNodeB started ===
Type <t> to view trace
RACH:  tti=2961, cc=0, preamble=6, offset=34, temp_crnti=0x46
RACH:  tti=2981, cc=0, preamble=9, offset=34, temp_crnti=0x47
RACH:  tti=3001, cc=0, preamble=46, offset=34, temp_crnti=0x48
RACH:  tti=3021, cc=0, preamble=21, offset=34, temp_crnti=0x49
Disconnecting rnti=0x46.
RACH:  tti=3041, cc=0, preamble=35, offset=34, temp_crnti=0x4a
Disconnecting rnti=0x47.
Disconnecting rnti=0x48.
Disconnecting rnti=0x49.
Disconnecting rnti=0x4a.
RACH:  tti=8541, cc=0, preamble=5, offset=34, temp_crnti=0x4b
RACH:  tti=8561, cc=0, preamble=43, offset=34, temp_crnti=0x4c
RACH:  tti=8581, cc=0, preamble=6, offset=34, temp_crnti=0x4d
RACH:  tti=8601, cc=0, preamble=38, offset=34, temp_crnti=0x4e
Disconnecting rnti=0x4b.
Disconnecting rnti=0x4c.
Disconnecting rnti=0x4d.
Disconnecting rnti=0x4e.

ue.log

19:40:59.749153 [PHY    ] [W] [ 2676] SFN not yet synchronized, sending out-of-sync
19:40:59.750913 [PHY    ] [W] [ 2676] SNR=1.1 dB RSRP=-91.7 dBm, sync=out-of-sync from channel estimator
19:40:59.751072 [PHY    ] [W] [ 2677] SFN not yet synchronized, sending out-of-sync
19:40:59.752431 [PHY    ] [W] [ 2677] SNR=1.1 dB RSRP=-91.7 dBm, sync=out-of-sync from channel estimator
19:40:59.752695 [PHY    ] [W] [ 2678] SFN not yet synchronized, sending out-of-sync
19:40:59.764214 [PHY    ] [W] [ 2678] SNR=1.0 dB RSRP=-91.7 dBm, sync=out-of-sync from channel estimator
19:40:59.764433 [PHY    ] [W] [ 2679] SFN not yet synchronized, sending out-of-sync
19:40:59.764860 [PHY    ] [W] [ 2679] SNR=1.0 dB RSRP=-91.7 dBm, sync=out-of-sync from channel estimator
19:40:59.765657 [PHY    ] [W] [ 2679] SNR=1.1 dB RSRP=-91.4 dBm, sync=out-of-sync from channel estimator
19:40:59.766852 [PHY    ] [W] [ 2679] SNR=1.1 dB RSRP=-91.5 dBm, sync=out-of-sync from channel estimator

this just goes on and on....

and enb.log

19:40:45.312925 [ENB    ] [I] Using binary srsenb with arguments: --expert.max_prach_offset_us=180 --rf.time_adv_nsamples=200
19:40:45.313072 [ENB    ] [I] Built in Release mode using commit 89f16eed2 on branch master.
19:40:45.350626 [RF     ] [I] Configuring physical DL channel 0 with band-pass filter (0.0, 0.0)
19:40:45.350633 [RF     ] [I] Configuring physical UL channel 0 with band-pass filter (0.0, 0.0)
19:40:45.798256 [PHY0   ] [I] [    0] Component Carrier Worker 0 configured cell 50 PRB
19:40:45.798294 [PHY0   ] [I] [    0] Worker 0 configured cell 50 PRB
19:40:45.913617 [PHY1   ] [I] [    0] Component Carrier Worker 0 configured cell 50 PRB
19:40:45.913651 [PHY1   ] [I] [    0] Worker 0 configured cell 50 PRB
19:40:46.028976 [PHY2   ] [I] [    0] Component Carrier Worker 0 configured cell 50 PRB
19:40:46.029009 [PHY2   ] [I] [    0] Worker 0 configured cell 50 PRB
19:40:46.044308 [RF     ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_tx=2680.0 MHz
19:40:46.046227 [MAC    ] [I] [    0] Resetting MAC
19:40:46.046251 [RF     ] [I] Mapping RF channel 0 (device=0, channel=0) to logical carrier 0 on f_rx=2560.0 MHz
19:40:46.084462 [RRC    ] [I] CC0 SIB payload - Tx systemInformationBlockType1 (15 B)
19:40:46.084473 [RRC    ] [I] CC0 SIB payload - Tx systemInformation (33 B)
19:40:46.084475 [RRC    ] [I] Allocating 1 PRBs for PUCCH
19:40:46.084638 [MAC    ] [I] [    0] Using time-domain PF scheduling policy for cc=0
19:40:46.084672 [RRC    ] [I] T310 200, T311 10000, N310 1
19:40:46.084673 [RRC    ] [I] Inactivity timeout: 30000 ms
19:40:46.084674 [RRC    ] [I] Max consecutive MAC KOs: 100
19:40:46.084676 [S1AP   ] [I] Proc "MME Connection" - Starting new MME connection.
19:40:46.084677 [S1AP   ] [I] Connecting to MME 127.0.1.100:36412
19:40:46.084696 [COMN   ] [D] [    0] Setting RTO_INFO options on SCTP socket. Association 0, Initial RTO 3000, Minimum RTO 1000, Maximum RTO 6000
19:40:46.084699 [COMN   ] [D] [    0] Setting SCTP_INITMSG options on SCTP socket. Max attempts 3, Max init attempts timeout 5000
19:40:46.084706 [S1AP   ] [I] SCTP socket opened. fd=12
19:40:46.084795 [S1AP   ] [I] SCTP socket connected with MME. fd=12
19:40:46.084804 [COMN   ] [D] [    0] RxSockets: socket fd=12 has been registered.
19:40:46.084807 [S1AP   ] [I] SCTP socket established with MME
19:40:46.084818 [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
19:40:46.084851 [S1AP   ] [I] Proc "MME Connection" - S1SetupRequest sent. Waiting for response...
19:40:46.084875 [COMN   ] [D] [    0] RxSockets: socket fd=13 has been registered.
19:40:46.089495 [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
19:40:46.089503 [S1AP   ] [I] Proc "MME Connection" - S1Setup procedure completed successfully
19:40:51.708379 [MAC    ] [I] [ 5641] SCHED: Added user rnti=0x46
19:40:51.708395 [MAC    ] [I] [ 5641] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:51.708398 [MAC    ] [I] [ 5641] SCHED: rnti=0x46 PCell is now enb_cc_idx=0
19:40:51.708419 [RRC    ] [I] Allocated SR resources in time-freq slot (0, 0), sf_cfg_idx=0
19:40:51.708421 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 0), n_pucch_2=0, pmi_cfg_idx=38
19:40:51.708460 [RRC    ] [I] Setting RLF timer for rnti=0x46 to 10201ms
19:40:51.708486 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.708489 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.708502 [RRC    ] [I] Added new user rnti=0x46
19:40:51.708514 [MAC    ] [I] [ 5641] SCHED: New PRACH tti=5641, preamble=22, temp_crnti=0x46, ta_cmd=34, msg3_size=7
19:40:51.708518 [MAC    ] [I] [ 5641] RACH:  tti=5641, cc=0, preamble=22, offset=34, temp_crnti=0x46
19:40:51.708557 [MAC    ] [I] [ 5641] rach_tprof: {mean, max, min}={277.9, 277, 277} usec, nof_samples=1
19:40:51.709117 [MAC    ] [I] [ 5642] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x46, rba=102, mcs=0}]
19:40:51.709237 [PHY1   ] [I] [ 5642] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=5646
19:40:51.709276 [PHY1   ] [I] [ 5642] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=5646
19:40:51.711049 [MAC    ] [I] [ 5644] SCHED: Msg3 tx rnti=0x46, cc=0, pid=4, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:51.719857 [PHY1   ] [I] [ 5652] PUSCH: cc=0, rnti=0x46, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=0.0 dB, epre=-16.8 dBfs, ta=0.5 us, cfo=-261.3 hz, t=92 us
19:40:51.719901 [MAC    ] [I] [ 5652] SCHED: Msg3 retx rnti=0x46, cc=0, pid=4, dci=(0,0), prb=[2, 5), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:51.719932 [PHY1   ] [I] [ 5652] PHICH: rnti=0x46, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5656
19:40:51.727599 [PHY1   ] [I] [ 5660] PUSCH: cc=0, rnti=0x46, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=-0.5 dB, epre=-7.1 dBfs, ta=-17.4 us, cfo=-456.6 hz, t=90 us
19:40:51.727642 [MAC    ] [I] [ 5660] SCHED: Msg3 retx rnti=0x46, cc=0, pid=4, dci=(0,0), prb=[2, 5), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:51.727668 [PHY1   ] [I] [ 5660] PHICH: rnti=0x46, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5664
19:40:51.728777 [MAC    ] [I] [ 5661] SCHED: Added user rnti=0x47
19:40:51.728793 [MAC    ] [I] [ 5661] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:51.728796 [MAC    ] [I] [ 5661] SCHED: rnti=0x47 PCell is now enb_cc_idx=0
19:40:51.728821 [RRC    ] [I] Allocated SR resources in time-freq slot (1, 0), sf_cfg_idx=2
19:40:51.728825 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 1), n_pucch_2=0, pmi_cfg_idx=40
19:40:51.728862 [RRC    ] [I] Setting RLF timer for rnti=0x47 to 10201ms
19:40:51.728888 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.728898 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.728907 [RRC    ] [I] Added new user rnti=0x47
19:40:51.728915 [MAC    ] [I] [ 5661] SCHED: New PRACH tti=5661, preamble=21, temp_crnti=0x47, ta_cmd=34, msg3_size=7
19:40:51.728925 [MAC    ] [I] [ 5661] RACH:  tti=5661, cc=0, preamble=21, offset=34, temp_crnti=0x47
19:40:51.728959 [MAC    ] [I] [ 5661] rach_tprof: {mean, max, min}={294.7, 311, 277} usec, nof_samples=2
19:40:51.729483 [MAC    ] [I] [ 5662] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x47, rba=102, mcs=0}]
19:40:51.729566 [PHY1   ] [I] [ 5662] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=5666
19:40:51.729602 [PHY1   ] [I] [ 5662] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=5666
19:40:51.731418 [MAC    ] [I] [ 5664] SCHED: Msg3 tx rnti=0x47, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:51.735368 [PHY1   ] [I] [ 5668] PUSCH: cc=0, rnti=0x46, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=-0.4 dB, epre=-17.0 dBfs, ta=-17.9 us, cfo=-115.0 hz, t=90 us
19:40:51.735413 [MAC    ] [I] [ 5668] SCHED: Msg3 retx rnti=0x46, cc=0, pid=4, dci=(0,0), prb=[2, 5), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:51.735442 [PHY1   ] [I] [ 5668] PHICH: rnti=0x46, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5672
19:40:51.739248 [PHY1   ] [I] [ 5672] PUSCH: cc=0, rnti=0x47, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=-1.3 dB, epre=-16.9 dBfs, ta=-3.7 us, cfo=122.3 hz, t=86 us
19:40:51.739291 [MAC    ] [I] [ 5672] SCHED: Msg3 retx rnti=0x47, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:51.739318 [PHY1   ] [I] [ 5672] PHICH: rnti=0x47, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5676
19:40:51.743121 [PHY1   ] [I] [ 5676] PUSCH: cc=0, rnti=0x46, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-0.7 dB, epre=-17.1 dBfs, ta=-16.0 us, cfo=522.1 hz, t=86 us
19:40:51.743144 [MAC    ] [I] [ 5676] SCHED: discarding UL pid=4, tti=5676, maximum number of retx exceeded (4)
19:40:51.743196 [PHY1   ] [I] [ 5676] PHICH: rnti=0x46, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5680
19:40:51.747008 [PHY1   ] [I] [ 5680] PUSCH: cc=0, rnti=0x47, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=-0.7 dB, epre=-6.9 dBfs, ta=12.4 us, cfo=-62.4 hz, t=86 us
19:40:51.747055 [MAC    ] [I] [ 5680] SCHED: Msg3 retx rnti=0x47, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:51.747082 [PHY1   ] [I] [ 5680] PHICH: rnti=0x47, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5684
19:40:51.749536 [MAC    ] [I] [ 5681] SCHED: Added user rnti=0x48
19:40:51.749553 [MAC    ] [I] [ 5681] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:51.749555 [MAC    ] [I] [ 5681] SCHED: rnti=0x48 PCell is now enb_cc_idx=0
19:40:51.749576 [RRC    ] [I] Allocated SR resources in time-freq slot (2, 0), sf_cfg_idx=4
19:40:51.749579 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 2), n_pucch_2=0, pmi_cfg_idx=42
19:40:51.749883 [RRC    ] [I] Setting RLF timer for rnti=0x48 to 10201ms
19:40:51.749915 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.749917 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.749925 [RRC    ] [I] Added new user rnti=0x48
19:40:51.749927 [MAC    ] [I] [ 5682] SCHED: New PRACH tti=5681, preamble=0, temp_crnti=0x48, ta_cmd=45, msg3_size=7
19:40:51.749930 [MAC    ] [I] [ 5682] RACH:  tti=5681, cc=0, preamble=0, offset=45, temp_crnti=0x48
19:40:51.749971 [MAC    ] [I] [ 5682] rach_tprof: {mean, max, min}={374.8, 534, 277} usec, nof_samples=3
19:40:51.750826 [MAC    ] [I] [ 5683] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x48, rba=102, mcs=0}]
19:40:51.750942 [PHY0   ] [I] [ 5683] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=5687
19:40:51.750978 [PHY0   ] [I] [ 5683] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=5687
19:40:51.752742 [MAC    ] [I] [ 5685] SCHED: Msg3 tx rnti=0x48, cc=0, pid=5, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:51.755744 [PHY1   ] [I] [ 5688] PUSCH: cc=0, rnti=0x47, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=-0.6 dB, epre=-16.6 dBfs, ta=-13.8 us, cfo=424.9 hz, t=89 us
19:40:51.755792 [MAC    ] [I] [ 5688] SCHED: Msg3 retx rnti=0x47, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:51.755821 [PHY1   ] [I] [ 5688] PHICH: rnti=0x47, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5692
19:40:51.760589 [PHY0   ] [I] [ 5693] PUSCH: cc=0, rnti=0x48, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=-0.5 dB, epre=-16.6 dBfs, ta=20.6 us, cfo=-102.6 hz, t=87 us
19:40:51.760645 [MAC    ] [I] [ 5693] SCHED: Msg3 retx rnti=0x48, cc=0, pid=5, dci=(3,0), prb=[10, 13), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:51.760705 [PHY0   ] [I] [ 5693] PDCCH: cc=0, f=0, cce= 0, L=3, riv=110, mcs=30, rv=2, ndi=1, f_h=n/a, cqi=no, tpc_pusch=1, dmrs_cs=0, tti_tx_dl=5697
19:40:51.760717 [PHY0   ] [I] [ 5693] PHICH: rnti=0x48, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5697
19:40:51.763488 [PHY1   ] [I] [ 5696] PUSCH: cc=0, rnti=0x47, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-0.4 dB, epre=-16.7 dBfs, ta=-22.1 us, cfo=577.0 hz, t=86 us
19:40:51.763512 [MAC    ] [I] [ 5696] SCHED: discarding UL pid=0, tti=5696, maximum number of retx exceeded (4)
19:40:51.763569 [PHY1   ] [I] [ 5696] PHICH: rnti=0x47, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5700
19:40:51.768246 [PHY0   ] [I] [ 5701] Adaptive retx: rnti=0x48, pid=1, rv_idx=2, mcs=30, old_tbs=7
19:40:51.768408 [PHY0   ] [I] [ 5701] PUSCH: cc=0, rnti=0x48, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=-1.7 dB, epre=-11.3 dBfs, ta=-15.4 us, cfo=231.8 hz, t=112 us
19:40:51.768471 [MAC    ] [I] [ 5701] SCHED: Msg3 retx rnti=0x48, cc=0, pid=5, dci=(0,0), prb=[10, 13), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:51.768562 [PHY0   ] [I] [ 5701] PHICH: rnti=0x48, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5705
19:40:51.768604 [MAC    ] [I] [ 5701] SCHED: Added user rnti=0x49
19:40:51.768615 [MAC    ] [I] [ 5701] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:51.768618 [MAC    ] [I] [ 5701] SCHED: rnti=0x49 PCell is now enb_cc_idx=0
19:40:51.768664 [RRC    ] [I] Allocated SR resources in time-freq slot (3, 0), sf_cfg_idx=6
19:40:51.768666 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 3), n_pucch_2=0, pmi_cfg_idx=44
19:40:51.768716 [RRC    ] [I] Setting RLF timer for rnti=0x49 to 10201ms
19:40:51.768735 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.768737 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.768746 [RRC    ] [I] Added new user rnti=0x49
19:40:51.768749 [MAC    ] [I] [ 5701] SCHED: New PRACH tti=5701, preamble=4, temp_crnti=0x49, ta_cmd=34, msg3_size=7
19:40:51.768750 [MAC    ] [I] [ 5701] RACH:  tti=5701, cc=0, preamble=4, offset=34, temp_crnti=0x49
19:40:51.768780 [MAC    ] [I] [ 5701] rach_tprof: {mean, max, min}={369.2, 534, 277} usec, nof_samples=4
19:40:51.769281 [MAC    ] [I] [ 5702] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x49, rba=102, mcs=0}]
19:40:51.769365 [PHY1   ] [I] [ 5702] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=5706
19:40:51.769405 [PHY1   ] [I] [ 5702] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=5706
19:40:51.771188 [MAC    ] [I] [ 5704] SCHED: Msg3 tx rnti=0x49, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:51.776123 [PHY0   ] [I] [ 5709] PUSCH: cc=0, rnti=0x48, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=-1.0 dB, epre=-17.0 dBfs, ta=-15.3 us, cfo=763.6 hz, t=89 us
19:40:51.776173 [MAC    ] [I] [ 5709] SCHED: Msg3 retx rnti=0x48, cc=0, pid=5, dci=(0,0), prb=[10, 13), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:51.776203 [PHY0   ] [I] [ 5709] PHICH: rnti=0x48, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5713
19:40:51.779035 [PHY1   ] [I] [ 5712] PUSCH: cc=0, rnti=0x49, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=-0.3 dB, epre=-16.6 dBfs, ta=21.0 us, cfo=-904.4 hz, t=86 us
19:40:51.779083 [MAC    ] [I] [ 5712] SCHED: Msg3 retx rnti=0x49, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:51.779112 [PHY1   ] [I] [ 5712] PHICH: rnti=0x49, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5716
19:40:51.784829 [PHY0   ] [I] [ 5717] PUSCH: cc=0, rnti=0x48, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-1.2 dB, epre=-17.0 dBfs, ta=-9.3 us, cfo=693.5 hz, t=87 us
19:40:51.784855 [MAC    ] [I] [ 5717] SCHED: discarding UL pid=5, tti=5717, maximum number of retx exceeded (4)
19:40:51.784894 [PHY0   ] [I] [ 5717] PHICH: rnti=0x48, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5721
19:40:51.787738 [PHY1   ] [I] [ 5720] PUSCH: cc=0, rnti=0x49, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=-0.6 dB, epre=-7.4 dBfs, ta=-27.4 us, cfo=586.9 hz, t=86 us
19:40:51.787792 [MAC    ] [I] [ 5720] SCHED: Msg3 retx rnti=0x49, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:51.787819 [PHY1   ] [I] [ 5720] PHICH: rnti=0x49, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5724
19:40:51.788513 [RRC    ] [I] Activity timer for rnti=0x46 expired after 80 ms
19:40:51.788602 [RRC    ] [I] Disconnecting rnti=0x46.
19:40:51.788623 [GTPU   ] [I] Removing user - rnti=0x46 not found.
19:40:51.788640 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 0)
19:40:51.788642 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 0)
19:40:51.788656 [RRC    ] [I] Removed user rnti=0x46
19:40:51.789356 [MAC    ] [I] [ 5721] SCHED: Added user rnti=0x4a
19:40:51.789391 [MAC    ] [I] [ 5721] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:51.789394 [MAC    ] [I] [ 5721] SCHED: rnti=0x4a PCell is now enb_cc_idx=0
19:40:51.789430 [RRC    ] [I] Allocated SR resources in time-freq slot (0, 0), sf_cfg_idx=0
19:40:51.789432 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 0), n_pucch_2=0, pmi_cfg_idx=38
19:40:51.789750 [RRC    ] [I] Setting RLF timer for rnti=0x4a to 10201ms
19:40:51.789767 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.789769 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:51.789779 [RRC    ] [I] Added new user rnti=0x4a
19:40:51.789801 [MAC    ] [I] [ 5722] SCHED: New PRACH tti=5721, preamble=51, temp_crnti=0x4a, ta_cmd=34, msg3_size=7
19:40:51.789802 [MAC    ] [I] [ 5722] RACH:  tti=5721, cc=0, preamble=51, offset=34, temp_crnti=0x4a
19:40:51.789850 [MAC    ] [I] [ 5722] rach_tprof: {mean, max, min}={415.0, 598, 277} usec, nof_samples=5
19:40:51.790657 [MAC    ] [I] [ 5723] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x4a, rba=102, mcs=0}]
19:40:51.790742 [PHY0   ] [I] [ 5723] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=5727
19:40:51.790781 [PHY0   ] [I] [ 5723] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=5727
19:40:51.792516 [MAC    ] [I] [ 5725] SCHED: Msg3 tx rnti=0x4a, cc=0, pid=5, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:51.795523 [PHY1   ] [I] [ 5728] PUSCH: cc=0, rnti=0x49, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=0.0 dB, epre=-16.7 dBfs, ta=13.7 us, cfo=-412.1 hz, t=91 us
19:40:51.795577 [MAC    ] [I] [ 5728] SCHED: Msg3 retx rnti=0x49, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:51.795610 [PHY1   ] [I] [ 5728] PHICH: rnti=0x49, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5732
19:40:51.798489 [MAC    ] [I] [ 5731] User rnti=0x46 removed from MAC/PHY
19:40:51.800378 [PHY0   ] [I] [ 5733] PUSCH: cc=0, rnti=0x4a, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=-0.0 dB, epre=-16.6 dBfs, ta=13.1 us, cfo=890.6 hz, t=87 us
19:40:51.800434 [MAC    ] [I] [ 5733] SCHED: Msg3 retx rnti=0x4a, cc=0, pid=5, dci=(3,0), prb=[10, 13), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:51.800497 [PHY0   ] [I] [ 5733] PDCCH: cc=0, f=0, cce= 0, L=3, riv=110, mcs=30, rv=2, ndi=1, f_h=n/a, cqi=no, tpc_pusch=1, dmrs_cs=0, tti_tx_dl=5737
19:40:51.800509 [PHY0   ] [I] [ 5733] PHICH: rnti=0x4a, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5737
19:40:51.803271 [PHY1   ] [I] [ 5736] PUSCH: cc=0, rnti=0x49, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-0.4 dB, epre=-16.3 dBfs, ta=11.7 us, cfo=-519.1 hz, t=86 us
19:40:51.803301 [MAC    ] [I] [ 5736] SCHED: discarding UL pid=0, tti=5736, maximum number of retx exceeded (4)
19:40:51.803357 [PHY1   ] [I] [ 5736] PHICH: rnti=0x49, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=5740
19:40:51.807911 [RRC    ] [I] Activity timer for rnti=0x47 expired after 80 ms
19:40:51.807974 [RRC    ] [I] Disconnecting rnti=0x47.
19:40:51.808011 [GTPU   ] [I] Removing user - rnti=0x47 not found.
19:40:51.808029 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 1)
19:40:51.808031 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 1)
19:40:51.808040 [PHY0   ] [I] [ 5741] Adaptive retx: rnti=0x4a, pid=1, rv_idx=2, mcs=30, old_tbs=7
19:40:51.808046 [RRC    ] [I] Removed user rnti=0x47
19:40:51.808169 [PHY0   ] [I] [ 5741] PUSCH: cc=0, rnti=0x4a, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=1.3 dB, epre=-17.1 dBfs, ta=-2.2 us, cfo=181.1 hz, t=84 us
19:40:51.808221 [MAC    ] [I] [ 5741] SCHED: Msg3 retx rnti=0x4a, cc=0, pid=5, dci=(0,0), prb=[10, 13), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:51.808293 [PHY0   ] [I] [ 5741] PHICH: rnti=0x4a, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5745
19:40:51.816868 [PHY0   ] [I] [ 5749] PUSCH: cc=0, rnti=0x4a, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=-1.0 dB, epre=-17.6 dBfs, ta=-22.7 us, cfo=361.2 hz, t=93 us
19:40:51.816921 [MAC    ] [I] [ 5749] SCHED: Msg3 retx rnti=0x4a, cc=0, pid=5, dci=(0,0), prb=[10, 13), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:51.816954 [PHY0   ] [I] [ 5749] PHICH: rnti=0x4a, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5753
19:40:51.818876 [MAC    ] [I] [ 5751] User rnti=0x47 removed from MAC/PHY
19:40:51.824620 [PHY0   ] [I] [ 5757] PUSCH: cc=0, rnti=0x4a, rb=(10,12), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-1.2 dB, epre=-17.1 dBfs, ta=-10.6 us, cfo=863.6 hz, t=91 us
19:40:51.824652 [MAC    ] [I] [ 5757] SCHED: discarding UL pid=5, tti=5757, maximum number of retx exceeded (4)
19:40:51.824685 [PHY0   ] [I] [ 5757] PHICH: rnti=0x4a, hi=0, I_lowest=10, n_dmrs=0, tti_tx_dl=5761
19:40:51.828289 [RRC    ] [I] Activity timer for rnti=0x48 expired after 80 ms
19:40:51.828351 [RRC    ] [I] Disconnecting rnti=0x48.
19:40:51.828389 [GTPU   ] [I] Removing user - rnti=0x48 not found.
19:40:51.828406 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 2)
19:40:51.828409 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 2)
19:40:51.828424 [RRC    ] [I] Removed user rnti=0x48
19:40:51.838246 [MAC    ] [I] [ 5771] User rnti=0x48 removed from MAC/PHY
19:40:51.848654 [RRC    ] [I] Activity timer for rnti=0x49 expired after 80 ms
19:40:51.848718 [RRC    ] [I] Disconnecting rnti=0x49.
19:40:51.848756 [GTPU   ] [I] Removing user - rnti=0x49 not found.
19:40:51.848774 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 3)
19:40:51.848776 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 3)
19:40:51.848791 [RRC    ] [I] Removed user rnti=0x49
19:40:51.858660 [MAC    ] [I] [ 5791] User rnti=0x49 removed from MAC/PHY
19:40:51.868061 [RRC    ] [I] Activity timer for rnti=0x4a expired after 80 ms
19:40:51.868160 [RRC    ] [I] Disconnecting rnti=0x4a.
19:40:51.868184 [GTPU   ] [I] Removing user - rnti=0x4a not found.
19:40:51.868203 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 0)
19:40:51.868206 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 0)
19:40:51.868225 [RRC    ] [I] Removed user rnti=0x4a
19:40:51.877925 [MAC    ] [I] [ 5810] User rnti=0x4a removed from MAC/PHY
19:40:56.808236 [MAC    ] [I] [  501] SCHED: Added user rnti=0x4b
19:40:56.808260 [MAC    ] [I] [  501] SCHED: bearer configured: lc_id=0, mode=bi-dir, prio=1
19:40:56.808263 [MAC    ] [I] [  501] SCHED: rnti=0x4b PCell is now enb_cc_idx=0
19:40:56.808277 [RRC    ] [I] Allocated SR resources in time-freq slot (0, 0), sf_cfg_idx=0
19:40:56.808278 [RRC    ] [I] Allocated CQI resources for ue_cc_idx=0, time-frequency slot (0, 0), n_pucch_2=0, pmi_cfg_idx=38
19:40:56.808299 [RRC    ] [I] Setting RLF timer for rnti=0x4b to 10201ms
19:40:56.808309 [RLC    ] [I] Added LTE radio bearer with LCID 0 in Transparent Mode
19:40:56.808310 [RLC    ] [I] Configured LTE radio bearer with LCID 0 in Transparent Mode
19:40:56.808315 [RRC    ] [I] Added new user rnti=0x4b
19:40:56.808316 [MAC    ] [I] [  501] SCHED: New PRACH tti=501, preamble=45, temp_crnti=0x4b, ta_cmd=34, msg3_size=7
19:40:56.808317 [MAC    ] [I] [  501] RACH:  tti=501, cc=0, preamble=45, offset=34, temp_crnti=0x4b
19:40:56.808348 [MAC    ] [I] [  501] rach_tprof: {mean, max, min}={374.1, 598, 169} usec, nof_samples=6
19:40:56.809108 [MAC    ] [I] [  502] SCHED: RAR, ra-rnti=2, rbgs=[0, 1), dci=(2,0), msg3 grants=[{c-rnti=0x4b, rba=102, mcs=0}]
19:40:56.809176 [PHY1   ] [I] [  502] PDCCH: cc=0, f=1A, cce= 0, L=2, riv=100, pid=0, mcs={1}, ndi={0}, tpc_pucch=0, tti_tx_dl=506
19:40:56.809220 [PHY1   ] [I] [  502] PDSCH: cc=0, rnti=0x2, nof_prb=3, nof_re=450, tbs={11}, mod={2}, rv={0}, tti_tx_dl=506
19:40:56.810975 [MAC    ] [I] [  504] SCHED: Msg3 tx rnti=0x4b, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=0, tbs=7, bsr=0 (0-7)
19:40:56.819804 [PHY1   ] [I] [  512] PUSCH: cc=0, rnti=0x4b, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=0, crc=KO, avg_iter=8.0, snr=-0.7 dB, epre=-16.6 dBfs, ta=-0.3 us, cfo=382.1 hz, t=66 us
19:40:56.819841 [MAC    ] [I] [  512] SCHED: Msg3 retx rnti=0x4b, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=1, tbs=7, bsr=0 (0-7)
19:40:56.819883 [PHY1   ] [I] [  512] PHICH: rnti=0x4b, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=516
19:40:56.827535 [PHY1   ] [I] [  520] PUSCH: cc=0, rnti=0x4b, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=2, crc=KO, avg_iter=8.0, snr=0.0 dB, epre=-16.5 dBfs, ta=23.2 us, cfo=205.9 hz, t=71 us
19:40:56.827567 [MAC    ] [I] [  520] SCHED: Msg3 retx rnti=0x4b, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=2, tbs=7, bsr=0 (0-7)
19:40:56.827583 [PHY1   ] [I] [  520] PHICH: rnti=0x4b, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=524
19:40:56.835301 [PHY1   ] [I] [  528] PUSCH: cc=0, rnti=0x4b, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=3, crc=KO, avg_iter=8.0, snr=-0.6 dB, epre=-16.4 dBfs, ta=0.0 us, cfo=166.6 hz, t=72 us
19:40:56.835334 [MAC    ] [I] [  528] SCHED: Msg3 retx rnti=0x4b, cc=0, pid=0, dci=(0,0), prb=[2, 5), n_rtx=3, tbs=7, bsr=0 (0-7)
19:40:56.835356 [PHY1   ] [I] [  528] PHICH: rnti=0x4b, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=532
19:40:56.843072 [PHY1   ] [I] [  536] PUSCH: cc=0, rnti=0x4b, rb=(2,4), nof_re=432, tbs=7, mod=2, rv=1, crc=KO, avg_iter=8.0, snr=-0.8 dB, epre=-16.3 dBfs, ta=-10.0 us, cfo=613.5 hz, t=59 us
19:40:56.843085 [MAC    ] [I] [  536] SCHED: discarding UL pid=0, tti=536, maximum number of retx exceeded (4)
19:40:56.843125 [PHY1   ] [I] [  536] PHICH: rnti=0x4b, hi=0, I_lowest=2, n_dmrs=0, tti_tx_dl=540
19:40:56.888432 [RRC    ] [I] Activity timer for rnti=0x4b expired after 80 ms
19:40:56.888457 [RRC    ] [I] Disconnecting rnti=0x4b.
19:40:56.888471 [GTPU   ] [I] Removing user - rnti=0x4b not found.
19:40:56.888498 [RRC    ] [I] Deallocated CQI resources for time-frequency slot (0, 0)
19:40:56.888503 [RRC    ] [I] Deallocated SR resources for time-frequency slot (0, 0)
19:40:56.888514 [RRC    ] [I] Removed user rnti=0x4b
19:40:56.897587 [MAC    ] [I] [  590] User rnti=0x4b removed from MAC/PHY
19:41:05.091391 [COMN   ] [D] [    0] RxSockets: Closing rx socket handler thread
19:41:05.092427 [COMN   ] [D] [    0] RxSockets: closed.

thanks for all the help. I'm just trying to a reasonable link going so i can work from there. If you think what i'm doing is just wrong, let me know.

@chuckixia chuckixia changed the title bladeRF with FPGA version 0.11.1 does appear to work with howto example bladeRF with FPGA version 0.11.1 does not work with howto example Jun 23, 2021
@andrepuschmann
Copy link
Collaborator

Hey,
that already looks a lot better.

If you've got a way for me to independently verify that with a smart phone, let me know :).

Well, a COTS phone is always an option to calibrate the eNB side first and make sure it works. You don't need much, such a SIM card, see https://docs.srsran.com/en/latest/app_notes/source/cots_ue/source/index.html for reference.

I've noticed you are using the native bladeRF driver in your tests. To be honest I haven't used them in a while and would actually recommend the Soapy driver instead. We do all our testing with it and they work just fine.

device_name = soapy
device_args = driver=bladerf

On the eNB side we don't use any time offset parameters either.

But it should work with the native blade RF driver as well. What you're stuck at right now is likely UL issues. Maybe gain, etc. What I would recommend as well is to use pdsch_ue/enb first to calibrate rx/tx gains.

Cheers
Andre

@chuckixia
Copy link
Author

I was looking into pdsch_ue/enb. But there doesn't seem to be a lot of documentation that I can find about how to use it. Can you point me to something?

@ign4z
Copy link

ign4z commented Feb 15, 2022 •
edited
Loading

I have the same problem here, I also tried with FPGA v0.14.0, I have a programmable SIM but srsenb don't show the network. @chuckixia Did you manage to solve the issue? your srsenb output and log looks very close to mine

@nobletrout
Copy link

hey man: https://github.com/nobletrout/srsRAN
the SPARROW branch
This gets the bladeRF to at least receive/send with enb from UE.

@ismagom ismagom closed this as completed Apr 14, 2023
@nitinvjain nitinvjain mentioned this issue Nov 21, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@andrepuschmann @ismagom @ign4z @nobletrout @chuckixia