Actions
Bug #4207
closedmulti-arfcn not working properly
Start date:
09/16/2019
Due date:
% Done:
100%
Spec Reference:
Description
I did some tests today with multi-arfcn with a B200 device (only kind of device supporting the feature now) before working on adding multiTRX support on LimeSDR (requires multi-arfcn support too).
I did some code clean up and applied some fixes submitted by other people. Some of them:
https://gerrit.osmocom.org/c/osmo-trx/+/15541 radioInterface: Mark setRxGain as virtual
https://gerrit.osmocom.org/c/osmo-trx/+/15542 Move multi-ARFCN chan amount modification from UHDDevice to parent class
https://gerrit.osmocom.org/c/osmo-trx/+/15413 Transceiver: Fixed copying of history into and from channelizer buffer.
https://gerrit.osmocom.org/c/osmo-trx/+/15521/1 radioInterfaceMulti: Override setTxGain() to avoid chan!=0 calls
I also had to --disable-sanitize on osmo-trx, otherwise I'm unable to have my laptop running everything on time.
I am using 2 TRX on ARFCN 870 and 872 (band 1800), and using channel allocator descend to have 2nd TRX being used at LU time.
Well, it seems RACH is working fine, but then after Assignment Request (on SDCCH in 2nd TRX), the BTS doesn't see any answer on that channel in the 2nd TRX.
However, some related notification seems to arrive to OsmoBTS but FN of the indication seems to be wrong:
20190916175256262 DRSL <0000> rsl.c:2948 (bts=0,trx=0,ts=0,ss=4) Fwd RLL msg CHAN_RQD from LAPDm to A-bis 20190916175256262 DRSL <0000> rsl.c:3042 (bts=0,trx=1,ts=0,pchan=SDCCH8) ss=0 Rx RSL CHAN_ACTIV 20190916175256262 DRSL <0000> rsl.c:1234 (bts=0,trx=1,ts=0,ss=0) chan_nr=SDCCH/8(0) on TS0 type=0x00 mode=SIGNALLING 20190916175256262 DL1C <0006> l1sap.c:1503 (bts=0,trx=1,ts=0,ss=0) activating channel chan_nr=SDCCH/8(0) on TS0 trx=1 20190916175256262 DL1C <0006> scheduler.c:981 Activating SDCCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> scheduler.c:981 Activating SACCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> scheduler.c:1029 Set mode 3, 0, handover 0 on SDCCH/8(0) of trx=1 ts=0 20190916175256262 DTRX <000b> trx_if.c:239 phy0.1: Enqueuing TRX control command 'CMD NOHANDOVER 0 0' 20190916175256262 DLLAPD <0011> lapd_core.c:296 Init DL layer: sequence range = 8, k = 1, history range = 2 (dl=0x7ffff6c1d388) 20190916175256262 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d388) 20190916175256262 DLLAPD <0011> lapd_core.c:296 Init DL layer: sequence range = 8, k = 1, history range = 2 (dl=0x7ffff6c1d510) 20190916175256262 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d510) 20190916175256262 DLLAPD <0011> lapd_core.c:296 Init DL layer: sequence range = 8, k = 1, history range = 2 (dl=0x7ffff6c1d6d8) 20190916175256262 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d6d8) 20190916175256262 DLLAPD <0011> lapd_core.c:296 Init DL layer: sequence range = 8, k = 1, history range = 2 (dl=0x7ffff6c1d860) 20190916175256262 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d860) 20190916175256262 DL1C <0006> scheduler.c:1094 Set a5/0 uplink for SDCCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> scheduler.c:1094 Set a5/0 uplink for SACCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> scheduler.c:1094 Set a5/0 downlink for SDCCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> scheduler.c:1094 Set a5/0 downlink for SACCH/8(0) on trx=1 ts=0 20190916175256262 DL1C <0006> l1sap.c:620 (bts=0,trx=1,ts=0,ss=0) activate confirm chan_nr=SDCCH/8(0) on TS0 trx=1 20190916175256262 DRSL <0000> rsl.c:810 (bts=0,trx=1,ts=0,pchan=SDCCH8) (ss=0) SDCCH Tx CHAN ACT ACK 20190916175256262 DTRX <000b> trx_if.c:581 phy0.1: Response message: 'RSP NOHANDOVER 0 0 0' 20190916175256262 DRSL <0000> rsl.c:2982 (bts=0,trx=0,ts=0,ss=0) Rx RSL IMM_ASS_CMD 20190916175256356 DTRX <000b> trx_if.c:120 phy0.0: Clock indication: fn=501217 20190916175256356 DL1C <0006> scheduler_trx.c:1796 TRX Clock Ind: elapsed_us= 997122, elapsed_fn=216, error_us= +282 20190916175256356 DL1C <0006> scheduler_trx.c:1815 GSM clock jitter: -3473us (elapsed_fn=0) 20190916175256367 DL1P <0007> scheduler.c:664 501260/378/06/32/12 (bts=0,trx=1,ts=0) SACCH/8(0): Prim 498274 vs exp 501260 = 2712662 <--- I added this print myself to log the difference, since I usually saw the line below: 20190916175256367 DL1P <0007> scheduler.c:666 501260/378/06/32/12 (bts=0,trx=1,ts=0) SACCH/8(0): Prim 2712662 is out of range (100), or channel (bts=0,trx=1,ts=0,ss=1) with type SACCH/8(0) is already disabled. If this happens in conjunction with PCU, increase 'rts-advance' by 5. 20190916175257354 DTRX <000b> trx_if.c:120 phy0.0: Clock indication: fn=501433 20190916175257354 DL1C <0006> scheduler_trx.c:1796 TRX Clock Ind: elapsed_us= 997662, elapsed_fn=216, error_us= +822 20190916175257354 DL1C <0006> scheduler_trx.c:1815 GSM clock jitter: -4218us (elapsed_fn=0) 20190916175258351 DTRX <000b> trx_if.c:120 phy0.0: Clock indication: fn=501650 20190916175258351 DL1C <0006> scheduler_trx.c:1796 TRX Clock Ind: elapsed_us= 997527, elapsed_fn=217, error_us=-3928 20190916175258351 DL1C <0006> scheduler_trx.c:1815 GSM clock jitter: -201us (elapsed_fn=0) 20190916175259263 DRSL <0000> rsl.c:3042 (bts=0,trx=1,ts=0,pchan=SDCCH8) ss=0 Rx RSL RF_CHAN_REL 20190916175259263 DL1C <0006> l1sap.c:1551 (bts=0,trx=1,ts=0,ss=0) deactivating channel chan_nr=SDCCH/8(0) on TS0 trx=1 20190916175259263 DL1C <0006> scheduler.c:981 Deactivating SACCH/8(0) on trx=1 ts=0 20190916175259263 DTRX <000b> trx_if.c:239 phy0.1: Enqueuing TRX control command 'CMD NOHANDOVER 0 0' 20190916175259263 DL1C <0006> scheduler.c:981 Deactivating SDCCH/8(0) on trx=1 ts=0 20190916175259263 DL1C <0006> l1sap.c:643 (bts=0,trx=1,ts=0,ss=0) deactivate confirm chan_nr=SDCCH/8(0) on TS0 trx=1 20190916175259263 DRSL <0000> rsl.c:789 (bts=0,trx=1,ts=0,pchan=SDCCH8) (ss=0) SDCCH Tx CHAN REL ACK 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_IDLE (dl=0x7ffff6c1d388) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d388) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_IDLE (dl=0x7ffff6c1d510) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d510) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_IDLE (dl=0x7ffff6c1d6d8) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d6d8) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_IDLE (dl=0x7ffff6c1d860) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d860) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d388) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d388) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d510) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d510) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d6d8) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d6d8) 20190916175259263 DLLAPD <0011> lapd_core.c:311 Resetting LAPDm instance 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_NULL -> LAPD_STATE_IDLE (dl=0x7ffff6c1d860) 20190916175259263 DLLAPD <0011> lapd_core.c:237 new state LAPD_STATE_IDLE -> LAPD_STATE_NULL (dl=0x7ffff6c1d860) 20190916175259263 DTRX <000b> trx_if.c:581 phy0.1: Response message: 'RSP NOHANDOVER 0 0 0'
So it seems some related indication is received but time seems to be incorrect and hecne the indication is dropped...
Files
Related issues
Actions
