Project

General

Profile

Bug #4102

osmo-bts-trx: incorrect PTCCH handling

Added by fixeria almost 2 years ago. Updated over 1 year ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
osmo-bts-trx
Target version:
-
Start date:
07/12/2019
Due date:
% Done:

100%

Spec Reference:
3GPP TS 45.002, 3GPP TS 45.010

Description

According to 3GPP TS 45.002, section 6.3.2.2.2, and 3GPP TS 45.010, section 3.3.4.2:

  • PTCCH/D (Packet Timing advance control channel, Downlink) is used to transmit Timing Advance updates for several MS. One PTCCH/D is paired with several PTCCH/U's. PTCCH/D frames are encoded using CS-1.
  • PTCCH/U (Packet Timing advance control channel, Uplink) is used to transmit random access bursts to allow estimation of the Timing Advance for one MS in packet transfer mode. PTCCH/U has 16 sub-channels (0..15) assigned to different MS using TAI.

Therefore, neither we properly handle Downlink PTCCH nor Uplink PTCCH in osmo-bts-trx:

https://git.osmocom.org/osmo-bts/tree/src/common/scheduler.c#n536

[TRXC_PTCCH] = {
    .name = "PTCCH", /* 3GPP TS 05.02, section 3.3.4.2 */
    .desc = "Packet Timing advance control channel",
    .chan_nr = RSL_CHAN_OSMO_PDCH,

    /* Same as for TRXC_BCCH (xCCH), see above. */
    .flags = TRX_CHAN_FLAG_PDCH,
    .rts_fn = rts_data_fn,
    .dl_fn = tx_data_fn, /* FIXME: we need tx_pdtch_fn() here! */
    .ul_fn = rx_data_fn, /* FIXME: we need rx_rach_fn() here! */
},
ptcch_errors_sc5_2.pcapng.gz ptcch_errors_sc5_2.pcapng.gz 440 KB pespin, 07/23/2019 07:06 PM

Related issues

Related to OsmoPCU - Feature #1545: continuous timing advance loop using PTCCHStalled02/23/2016

Associated revisions

Revision df5b813c (diff)
Added by Vadim Yanitskiy over 1 year ago

scheduler: fix handling of PTCCH/U and PTCCH/D logical channels

According to 3GPP TS 45.010, section 5.6.2, for packet-switched
channels the BTS shall monitor the delay of the Access Bursts
sent by the MS on PTCCH and respond with timing advance values
for all MS performing the procedure on that PDCH.

According to 3GPP TS 45.002, section 3.3.4.2, PTCCH (Packet Timing
advance control channel) is a packet dedicated channel, that is
used for continuous Timing Advance control (mentioned above).

There are two sub-types of that logical channel:

- PTCCH/U (Uplink): used to transmit random Access Bursts
to allow estimation of the Timing Advance for one MS in
packet transfer mode.
- PTCCH/D (Downlink): used by the network to transmit
Timing Advance updates for several MS.

As per 3GPP TS 45.003, section 5.2, the coding scheme used for
PTCCH/U is the same as for PRACH as specified in subclause 5.3,
while the coding scheme used for PTCCH/D is the same as for
CS-1 as specified in subclause 5.1.1.

The way we used to handle both PTCCH/U and PTCCH/D is absolutely
wrong - they have nothing to do with xCCH coding. Instead, we
need to use tx_pdtch_fn() for Downlink and rx_rach_fn() for Uplink.

In l1sap_ph_rach_ind() we need to check if an Access Burst was
received on PTCCH/U and forward it to OsmoPCU with proper SAPI
value (PCU_IF_SAPI_PTCCH). To be able to specify a SAPI, a new
parameter is introduced to pcu_tx_rach_ind().

Change-Id: I232e5f514fbad2c51daaa59ff516004aba97c8a3
Related: OS#4102

Revision a070e863 (diff)
Added by Vadim Yanitskiy over 1 year ago

pcuif_proto.h: extend RACH.ind with TRX and timeslot number fields

Since there can be multiple PDCH channels configured on different
timeslots, different TRXes, and BTSes, the PTCCH/U handling code
in OsmoPCU needs to know the exact origin of a given RACH.ind.

Otherwise, it is not known which subscriber originated a given
PTCCH/U indication, and hence it is impossible to send PTCCH/D
Timing Advance notification properly.

Fortunately, we can extend the RACH.ind message without even
bumping the protocol version, because every single PDU has a
fixed size defined by the largest message - INFO.ind. In case
if the actual message payload is smaller, the rest is filled
with a constant padding byte (0x00).

Older versions of OsmoPCU will consider the new fields as padding,
while the messages from older OsmoBTS versions will always have
both fields set to 0x00. Since C0/TS0 cannot be configured to
PDCH, this can be easily detected on the other end.

Change-Id: Iff38934a108b6b1cd298669834263a7d5296c3f6
Related: OS#4102, OS#1545

History

#1 Updated by fixeria almost 2 years ago

  • Related to Feature #1545: continuous timing advance loop using PTCCH added

#2 Updated by pespin over 1 year ago

Consequence of not having this implemented: rx_data_fn is used to decode the PTCCH bursts, and then these errors appear all the time with osmo-bts-trx connected to an SC5 TRX:

20190723193916529 DTRX <000b> trx_if.c:120 Clock indication: fn=79572
20190723193916529 DL1C <0006> scheduler_trx.c:1772 TRX Clock Ind: elapsed_us=1061562, elapsed_fn=230, error_us= +112
20190723193916529 DL1C <0006> scheduler_trx.c:1790 GSM clock jitter: -4601us (elapsed_fn=0)
20190723193916900 DL1P <0007> scheduler_trx.c:981 079650/60/12/39/34 (bts=0,trx=0,ts=6) PTCCH: Received bad data (79572/12)
20190723193916901 DL1P <0007> scheduler_trx.c:981 079650/60/12/39/34 (bts=0,trx=0,ts=7) PTCCH: Received bad data (79572/12)
20190723193917381 DL1P <0007> scheduler_trx.c:981 079754/60/12/41/34 (bts=0,trx=0,ts=6) PTCCH: Received bad data (79676/12)
20190723193917382 DL1P <0007> scheduler_trx.c:981 079754/60/12/41/34 (bts=0,trx=0,ts=7) PTCCH: Received bad data (79676/12)
20190723193917591 DTRX <000b> trx_if.c:120 Clock indication: fn=79802
20190723193917591 DL1C <0006> scheduler_trx.c:1772 TRX Clock Ind: elapsed_us=1061499, elapsed_fn=230, error_us=  +49
20190723193917591 DL1C <0006> scheduler_trx.c:1790 GSM clock jitter: -4584us (elapsed_fn=0)
20190723193917861 DL1P <0007> scheduler_trx.c:981 079858/60/12/43/34 (bts=0,trx=0,ts=6) PTCCH: Received bad data (79780/12)
20190723193917862 DL1P <0007> scheduler_trx.c:981 079858/60/12/43/34 (bts=0,trx=0,ts=7) PTCCH: Received bad data (79780/12)
20190723193918341 DL1P <0007> scheduler_trx.c:981 079962/60/12/45/38 (bts=0,trx=0,ts=6) PTCCH: Received bad data (79884/12)
20190723193918341 DL1P <0007> scheduler_trx.c:981 079962/60/12/45/38 (bts=0,trx=0,ts=7) PTCCH: Received bad data (79884/12)
20190723193918652 DTRX <000b> trx_if.c:120 Clock indication: fn=80032
20190723193918652 DL1C <0006> scheduler_trx.c:1772 TRX Clock Ind: elapsed_us=1061489, elapsed_fn=230, error_us=  +39
20190723193918652 DL1C <0006> scheduler_trx.c:1790 GSM clock jitter: -4558us (elapsed_fn=0)
20190723193918821 DL1P <0007> scheduler_trx.c:981 080066/60/12/47/38 (bts=0,trx=0,ts=6) PTCCH: Received bad data (79988/12)
20190723193918822 DL1P <0007> scheduler_trx.c:981 080066/60/12/47/38 (bts=0,trx=0,ts=7) PTCCH: Received bad data (79988/12)
20190723193919301 DL1P <0007> scheduler_trx.c:981 080170/60/12/49/42 (bts=0,trx=0,ts=6) PTCCH: Received bad data (80092/12)
20190723193919302 DL1P <0007> scheduler_trx.c:981 080170/60/12/49/42 (bts=0,trx=0,ts=7) PTCCH: Received bad data (80092/12)
20190723193919714 DTRX <000b> trx_if.c:120 Clock indication: fn=80262
20190723193919714 DL1C <0006> scheduler_trx.c:1772 TRX Clock Ind: elapsed_us=1061622, elapsed_fn=230, error_us= +172
20190723193919714 DL1C <0006> scheduler_trx.c:1790 GSM clock jitter: -4594us (elapsed_fn=0)
20190723193919780 DL1P <0007> scheduler_trx.c:981 080274/60/12/00/42 (bts=0,trx=0,ts=6) PTCCH: Received bad data (80196/12)
20190723193919781 DL1P <0007> scheduler_trx.c:981 080274/60/12/00/42 (bts=0,trx=0,ts=7) PTCCH: Received bad data (80196/12)
20190723193920261 DL1P <0007> scheduler_trx.c:981 080378/60/12/02/42 (bts=0,trx=0,ts=6) PTCCH: Received bad data (80300/12)
20190723193920261 DL1P <0007> scheduler_trx.c:981 080378/60/12/02/42 (bts=0,trx=0,ts=7) PTCCH: Received bad data (80300/12)
20190723193920740 DL1P <0007> scheduler_trx.c:981 080482/60/12/04/46 (bts=0,trx=0,ts=6) PTCCH: Received bad data (80404/12)
20190723193920741 DL1P <0007> scheduler_trx.c:981 080482/60/12/04/46 (bts=0,trx=0,ts=7) PTCCH: Received bad data (80404/12)
20190723193920775 DTRX <000b> trx_if.c:120 Clock indication: fn=80492

#3 Updated by fixeria over 1 year ago

[...] and then these errors appear all the time with osmo-bts-trx connected to an SC5 TRX [...]

I would really love to see a capture of the TRXD interface. We don't have PS Timing Advance control implemented at the moment, so I would expect nothing on PTCCH, excluding false-positive detections of course.

$ cd osmocom-bb/src/target/trx_toolkit/
$ sudo ./trx_sniff.py --direction L1 --timeslot 7 -p 5700 -o /tmp/ul_bursts.dump

#4 Updated by pespin over 1 year ago

Running the command in that scenario provides no L1 log lines and a .dump file of 0 bytes (I checked the tool works fine on another scenario with osmo-trx).

#5 Updated by pespin over 1 year ago

Sorry, it actually fins the packets, I was not passing the correct interface to sniff on. Once I set that correctly, .dump file is still 0 bytes, but I get lots of these messages:

[WARNING] trx_sniff.py:98 Failed to parse message, dropping...

#6 Updated by pespin over 1 year ago

I attach a raw pcap dump in case it's useful.

#7 Updated by fixeria over 1 year ago

Here is a part of what I've managed to decode from your capture:

$ ./trx_sniff.py -r /tmp/ptcch_errors_sc5_2.pcap --direction L1 --timeslot 6 --frame-count 52
[INFO] trx_sniff.py:72 Reading packets from '/tmp/ptcch_errors_sc5_2.pcap'...
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161148 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161149 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161150 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161151 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161152 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161153 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161154 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161155 tn=6 rssi=-102 toa256=256
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161156 tn=6 rssi=-103 toa256=-128
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161157 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161158 tn=6 rssi=-102 toa256=-448
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161159 tn=6 rssi=-102 toa256=448
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161160 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161161 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161162 tn=6 rssi=-103 toa256=0
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161163 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161164 tn=6 rssi=-103 toa256=0
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161165 tn=6 rssi=-103 toa256=640
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161166 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161167 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161168 tn=6 rssi=-103 toa256=-256
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161169 tn=6 rssi=-103 toa256=-448
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161170 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161171 tn=6 rssi=-102 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161172 tn=6 rssi=-103 toa256=448
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161173 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161174 tn=6 rssi=-102 toa256=-320
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161175 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161176 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161177 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161178 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161179 tn=6 rssi=-102 toa256=-192
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161180 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161181 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161182 tn=6 rssi=-102 toa256=-320
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161183 tn=6 rssi=-102 toa256=-320
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161184 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161185 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161186 tn=6 rssi=-103 toa256=64
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161187 tn=6 rssi=-103 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161188 tn=6 rssi=-102 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161189 tn=6 rssi=-102 toa256=256
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161190 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161191 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161192 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161193 tn=6 rssi=-102 toa256=-512
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161194 tn=6 rssi=-102 toa256=-320
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161195 tn=6 rssi=-103 toa256=704
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161196 tn=6 rssi=-103 toa256=-448
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161197 tn=6 rssi=-103 toa256=-320
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161198 tn=6 rssi=-103 toa256=768
[DEBUG] trx_sniff.py:125 TRX -> L1 burst: fn=1161199 tn=6 rssi=-103 toa256=768
[INFO] trx_sniff.py:188 Collected required amount of frames
[INFO] trx_sniff.py:194 Shutting down...
[INFO] trx_sniff.py:198 52 bursts handled, 738 dropped

As far as I can see, your SC5 TRX detects pretty much everything on PDCH - just look at TDMA frame numbers.
RSSI is quite low (looks like noise), while ToA256 values are not that bad...

You don't see PDTCH decoding errors because unlike rx_data_fn(), rx_pdtch_fn() uses LOGL_DEBUG:

LOGL1S(DL1P, LOGL_DEBUG, l1t, bi->tn, chan, bi->fn, "Received bad PDTCH (%u/%u)\n", ...);
LOGL1S(DL1P, LOGL_NOTICE, l1t, bi->tn, chan, bi->fn, "Received bad data (%u/%u)\n", ...);

Looks like a problem of SC5. Feel free to investigate and fill a separate bug report.

#8 Updated by pespin over 1 year ago

Related patches for trxcon:
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/15637
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/15638

Something similar needs to be done in osmo-bts-trx.

#9 Updated by fixeria over 1 year ago

  • Status changed from New to In Progress
  • Assignee set to fixeria

#10 Updated by fixeria over 1 year ago

  • Status changed from In Progress to Feedback
  • % Done changed from 0 to 80

Please see: https://gerrit.osmocom.org/c/osmo-bts/+/15656 scheduler: fix handling of PTCCH/U and PTCCH/D logical channels.
Now we need a TTCN-3 test case to verify PTCCH operation in both directions (changes for trxcon need to be merged first).

#11 Updated by fixeria over 1 year ago

  • % Done changed from 80 to 100

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/15792 BTS_Tests.ttcn: add a test case for PTCCH/D and PTCCH/U

#12 Updated by fixeria over 1 year ago

  • Status changed from Feedback to Resolved

Merged.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)