Project

General

Profile

Bug #4799

Both TC_meas_res_sign_tchh and TC_meas_res_sign_tchh_toa256 are failing

Added by laforge about 2 months ago. Updated 4 days ago.

Status:
In Progress
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
10/11/2020
Due date:
% Done:

80%

Spec Reference:

Description

The test verifying measurement results for TCH/H is failing consistently at all time.

MTC@nataraja: Local verdict of PTC TC_meas_res_sign_tchh(6): fail (none -> fail) reason: ""BTS_Tests.ttcn:1945 : Received unspecific MEAS RES { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_MEAS_RES (40), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { lm := { tag := '0001'B, sub_chan := 0 } }, tn := 5 } } }, { iei := RSL_IE_MEAS_RES_NR (27), body := { meas_res_nr := 1 } }, { iei := RSL_IE_UPLINK_MEAS (25), body := { uplink_meas := { len := 3, rfu := '0'B, dtx_d := false, rxlev_f_u := 10, reserved1 := '00'B, rxlev_s_u := 10, reserved2 := '00'B, rxq_f_u := 7, rxq_s_u := 7, supp_meas_info := omit } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_L1_INFO (10), body := { l1_info := { ms_power_lvl := 7, fpc := false, reserved := 0, actual_ta := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 6, payload := '061539390000'O } } }, { iei := RSL_IE_MS_TIMING_OFFSET (37), body := { ms_timing_offset := 65 } } } }"" 

What seems odd is that RxQual=7 for the uplink measurement report generated by the BTS. Note this is not the first measurement report after channel activation, but already the second, where we would normally expect all bursts to arrive with perfect quality.

invalid_channel_mode_IE.png View invalid_channel_mode_IE.png 81.2 KB dexter, 10/14/2020 06:35 PM
FACCH_H-1.jpg View FACCH_H-1.jpg 810 KB fixeria, 10/23/2020 08:05 PM
osmo_bts_trx_tch_f_facch.log osmo_bts_trx_tch_f_facch.log 135 KB dexter, 11/23/2020 04:00 PM
osmo_bts_trx_tch_h_facch.log osmo_bts_trx_tch_h_facch.log 418 KB dexter, 11/23/2020 04:00 PM
sysmo_bts_tch_f_facch.log sysmo_bts_tch_f_facch.log 43.1 KB dexter, 11/23/2020 04:00 PM
sysmo_bts_tch_h_facch.log sysmo_bts_tch_h_facch.log 89.6 KB dexter, 11/23/2020 04:00 PM
4314
4323

History

#1 Updated by dexter about 2 months ago

  • Status changed from New to In Progress

#2 Updated by dexter about 2 months ago

  • % Done changed from 0 to 20

I think I have now found out what causes the problem. TC_meas_res_sign_tchh activates the TCH/H as signalling channel SDCCH. This seems to change the measurement reporting interval.

To my understanding the measurement interval for SDCCH/SACCH would look like:

                                                                                                    1
          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v
MEASUREMENT REPORTING TCH/H TS4/TS5.0
---------------------------------------------------||---------------------------------------------------
DdDdDdDdDdDdSDdDdDdDdDdDdsDdDdDdDdDdDdSDdDdDdDdDdDdsDdDdDdDdDdDdSDdDdDdDdDdDdsDdDdDdDdDdDdSDdDdDdDdDdDds
M       M        M        M       M        M        M       M   M    M        M       M        M      
                                      A                         .
                                      |______remaps to__________|

From this we can expect 13 measurements instead of 25. Since the number of the measurements is included into the rxqual calculation the we get values that are far of here. This is why the TTCN3 test fails.

Unfortunately I am not sure if this is correct. In GSM 04.03 I find in chapter 6 Channel configurations that SDCCH + SACCH is a valid configuration. So I think technically this is just a FACCH that is permanently present. I assume that allocating an SDCCH on was tested/used (was it?) in real life setups before, so we can be sure that the signalling data that is decoded from here makes sense.

Given that my assumptions are correct I would ajust the expected number of measurements (this number is used to check if measurements are missing and replaces the missing ones => wrong rxqual) to 13 when the channel is in signalling mode (3).

#3 Updated by fixeria about 2 months ago

Hi Philipp,

I think I have now found out what causes the problem. TC_meas_res_sign_tchh activates the TCH/H as signalling channel SDCCH.

I am sorry, but this is incorrect. TCH in signalling mode is still a TCH (i.e. traffic channel), not an SDCCH (i.e. dedicated control channel). The only difference from 'speech' mode is that both sides always send FACCH frames instead of speech frames. The multi-frame layout and thus the measurement reporting interval remain the same.

Best regards,
Vadim.

#4 Updated by laforge about 2 months ago

Hi Philipp,

On Tue, Oct 13, 2020 at 09:15:55PM +0000, dexter [REDMINE] wrote:

I think I have now found out what causes the problem. TC_meas_res_sign_tchh activates the TCH/H as signalling channel SDCCH.

this is clearly invalid. The TCH/H must be activated as TCH/H in signaling mode, and nothing else.

#5 Updated by dexter about 2 months ago

4314

this is clearly invalid. The TCH/H must be activated as TCH/H in signaling mode, and nothing else.

I see, makes also more sense to me. I have fixed that now in the tests:
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20645 BTS_Tests: fix CHANnel ACTIVation message in TC_meas_res_sign_tchX

#6 Updated by dexter about 2 months ago

The Fix above will not make the test pass. It just fixes the odd CHANnel ACTIVation message. There is a wired problem in osmo-bts-trx for signalling channels the measurement reporting is definetly broken, for normal TCH/H/FACCH+SACCH usage things should be fine, but this seems to be more by chance as the logic around this is not obvious. I can fix this, but I think we need a bit more test coverage. (there is also still #3780)

I wonder if f_TC_meas_res_periodic could be modified so that it tests real TCH/H and not only the signalling case. For sure it is easily possible to activate the channel as TCH/H in GSM V1 speech mode for example but this still does not change the fact that only FACCH (L1CTL_DATA_IND) are sent by the testcase (are they really or is this generated by TRXCON because the testcase does not send any traffic). I would need L1CTL_TRAFFIC_IND to be send to TRXCON which contain GSM V1 voice frames.

There is this f_TC_meas_res_periodic() that uses as_l1_dcch(), I tried to make an as_l1_tch()

private altstep as_l1_tch() runs on ConnHdlr {
    var L1ctlDlMessage l1_dl;
    [] L1CTL.receive(tr_L1CTL_TRAFFIC_IND(g_chan_nr, tr_RslLinkID_DCCH(?))) -> value l1_dl {
        log("TCH received: ", l1_dl.payload.traffic_ind.data);
        var octetstring pl := '010301'O;
        log("=====================> I AM SENDING TO L1CTL:");
        log(ts_L1CTL_TRAFFIC_REQ(g_chan_nr, ts_RslLinkID_DCCH(0),
            f_pad_oct(pl, 23, '2B'O)));

        L1CTL.send(ts_L1CTL_TRAFFIC_REQ(g_chan_nr, ts_RslLinkID_DCCH(0),
            f_pad_oct(pl, 23, '2B'O)));
        repeat;
        }
}
<pre>

But that did not work, which might be because there is never an tr_L1CTL_TRAFFIC_IND comming from TRXCON, shouldn't I receive something as soon as the channel is activated?

#7 Updated by fixeria about 1 month ago

Hi Philipp,

The Fix above will not make the test pass. It just fixes the odd CHANnel ACTIVation message.

I am wondering whether this 'Channel Rate and Type' IE is even considered in osmo-bts...

There is a wired problem in osmo-bts-trx for signalling channels the measurement reporting is definetly broken, for normal TCH/H/FACCH+SACCH usage things should be fine,

For measurement reporting on TCH/F or TCH/H there is no difference whether the channel is activated in signalling or in traffic mode - TCH is a separate channel, SACCH is a separate channel. Why do you think it should be fine for traffic?

I wonder if f_TC_meas_res_periodic could be modified so that it tests real TCH/H and not only the signalling case.

I don't think the 'traffic' mode would change anything (see above).

[] L1CTL.receive(tr_L1CTL_TRAFFIC_IND(g_chan_nr, tr_RslLinkID_DCCH(?))) -> value l1_dl
[...] shouldn't I receive something as soon as the channel is activated?

The problem is that you're not sending any RTP frames to the BTS, so you should see lots of:

DL1P INFO sched_lchan_tchf.c:539 001477/01/21/49/41 (bts=0,trx=0,ts=1) TCH/F: No TCH or FACCH prim for transmit.
DL1P INFO sched_lchan_tchf.c:539 001482/01/00/03/46 (bts=0,trx=0,ts=1) TCH/F: No TCH or FACCH prim for transmit.
DL1P INFO sched_lchan_tchf.c:539 001486/01/04/07/50 (bts=0,trx=0,ts=1) TCH/F: No TCH or FACCH prim for transmit.
DL1P INFO sched_lchan_tchf.c:539 001490/01/08/11/02 (bts=0,trx=0,ts=1) TCH/F: No TCH or FACCH prim for transmit.

Most likely, it's just sending dummy bursts (I would expect BFIs instead?), so trxcon fails to decode TCH/F blocks:

20201019024408686 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1788 for TCH/F
20201019024408704 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1792 for TCH/F
20201019024408727 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1797 for TCH/F
20201019024408746 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1801 for TCH/F
20201019024408764 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1805 for TCH/F
20201019024408787 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1810 for TCH/F
20201019024408806 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1814 for TCH/F
20201019024408824 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1818 for TCH/F
20201019024408847 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1823 for TCH/F
20201019024408866 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1827 for TCH/F
20201019024408884 DSCHD ERROR sched_lchan_tchf.c:127 Received bad TCH frame ending at fn=1831 for TCH/F

Best regards,
Vadim.

#8 Updated by fixeria about 1 month ago

  • % Done changed from 30 to 40

Hi Philipp,

The problem is that you're not sending any RTP frames to the BTS, so you should see lots of:

this still applies, but regardless of that trxcon must be sending BFIs to the test case. I did a quick investigation, and found out that the test suite does not send the correct TCH mode to trxcon, so trxcon always works in signalling mode and sends empty DATA.ind (indicating bad xCCCH frames) instead. Moreover, I found out that the 'L1ctlDmEstReq' definition in L1CTL_Types is incorrect:

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20753 library/L1CTL_PortType: fix indention in alt() statements [NEW]
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20754 library/L1CTL_Types: turn L1ctlTchMode into an enumerated type [NEW]
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20755 library/L1CTL_Types: fix definition of L1ctlDmEstReq [NEW]

I don't think the 'traffic' mode would change anything (see above).

I submitted an incomplete patch set (still need to fix some things):

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20756 BTS_Tests: cosmetic: rename 'as_l1_dcch' to 'as_l1_dcch_loop' [NEW]
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20757 BTS_Tests: introduce and use TCH loop - as_l1_tch_loop() [NEW]
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20758 BTS_Tests: introduce TC_meas_res_speech_tch{f,h} [NEW]

and indeed, you were right: both TC_meas_res_speech_tchf and TC_meas_res_speech_tchh pass. I am surprised.
Does it mean that the measurement processing logic in osmo-bts-trx is somehow wrong?

Best regards,
Vadim.

#9 Updated by fixeria about 1 month ago

  • Subject changed from TC_meas_res_sign_tchh failing to Both TC_meas_res_sign_tchh and TC_meas_res_sign_tchh_toa256 are failing

I also had a quick look at TC_meas_res_sign_tchh_toa256(), which currently aborts due to a DTE:

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20796 BTS_Tests: fix DTE in TC_meas_res_sign_tchh_toa256()

with this patch applied, it still does not pass, but it's 'speech' variant does:

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20797 BTS_Tests: introduce TC_meas_res_speech_tchh_toa256()

#10 Updated by dexter about 1 month ago

I have found out that the remaining reasons why TC_meas_res_sign_tchh_ are failing is a mishandling of the FACCH in sched_lchan_tchh.c. The signalling mode can be seen as a permanent FACCH transmission but without TCH indications (l1sap.c). Since the FACCH is spreaded over 6 bursts the amount of measurement values is halved. In order to correct the amount we could add each measurement we get from a FACCH twice. This is for sure debateable, but it corrects the amount of measurements. See also:

https://gerrit.osmocom.org/c/osmo-bts/+/20840 measurement: count measurements for FACCH/H twice.

For FACCH/F we have the opposite issue. Here it is actually simple to correct the problem. We just make sure that the TCH/F indication that is generated as a replacement for the missing speech block. Since FACCH/F blocks are exactly the same size as speech blocks everything mahctes up again. See also:

https://gerrit.osmocom.org/c/osmo-bts/+/20841 sched_lchan_tchf: count measurements for FACCH/F only once

In order to have a testbed for the FACCH debugging I have added tests that open the channel in speech mode while ocassionally injecting FACCH blocks. For TCH/F everything looks fine here, but even when the test passes for TCH/H it still looks very messy from inside of osmo-bts. Unfortunately there is no easy way to check if osmo-bts gets the right amount of upling measurements. A rate counter that is quieried from TTCN3 might help here.

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/20839 BTS_Tests: add FAACH to TC_meas_res_speech_tchX

So far now all tests should pass, even when I am not happy with the result. I have studied the specs and the FACCH behavior of osmo-bts but unfortunately I can not align the theory with the actual implementation. This was also the case when I was doing the AMR DTX implementation. However, here is the theory I currently know:


=============
== FACCH/F ==
=============

FACCH = F
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

MEASUREMENT REPORTING TCH/F TS1 (SIGNALLING)
------------||------------------------------------------------------------------------------------------
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
FFFFFFFFFFFFIFFFFFFFFFFFFSFFFFFFFFFFFFIFFFFFFFFFFFFSFFFFFFFFFFFFIFFFFFFFFFFFFSFFFFFFFFFFFFIFFFFFFFFFFFFS
M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M    

MEASUREMENT REPORTING TCH/F TS1 (SPEECH)
------------||------------------------------------------------------------------------------------------
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
TTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTS
M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M    

Possible slots to transmit a FACCH (same as for TCH)
M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M-------
----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M---

EXAMPLE: FACCH/F

------------||------------------------------------------------------------------------------------------
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
TTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTFFFFIFFFFTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTS
M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M

                  (FACCH)
                                  M        M
                       ...TTTTTTTTFFFFIFFFFTTTTTTTT...
                           ...TTTTTTTTITTTTTTTT...
                              M        M              
                       Note: The FACCH transmission is fully symmetric, which means
                     that one FACCH frame exactly replaces one voice frame.
                 The number of blocks and measurement results generated
                 for the higher layers remains constant.

=============
== FACCH/H ==
=============

FACCH = F for subchannel 0
FACCH = f for subchannel 1
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

MEASUREMENT REPORTING TCH/H TS4/TS5.0 (SIGNALLING)
---------------------------------------------------||---------------------------------------------------
FfFfFfFfFfFfSFfFfFfFfFfFfsFfFfFfFfFfFfSFfFfFfFfFfFfsFfFfFfFfFfFfSFfFfFfFfFfFfsFfFfFfFfFfFfSFfFfFfFfFfFfs
M       M        M        M       M        M        M       M   M    M        M       M        M      

MEASUREMENT REPORTING TCH/H TS4/TS5.0 (SPEECH)
---------------------------------------------------||---------------------------------------------------
TtTtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTts
M   M   M    M   M   M    M   M   M    M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M

Possible slots to transmit a FACCH on subchannel 0
M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -
- -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -

Possible slots to transmit a FACCH on subchannel 1
 M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -
 - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -

EXAMPLE: FACCH/H on SS0
MEASUREMENT REPORTING TCH/H TS4/TS5.0 (TRAFFIC)
---------------------------------------------------||---------------------------------------------------
TtTtTtTtTtTtSTtTtFtFtFtFtsFtFtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTts
M   M   M    M   M        M   M   M    M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M

             (FACCH)         
        M        M            M
     ...T T  T T F F F F  T T T T...
          ...T T T T F F  F F T T T T...
             M            M       M
     (measurement values positioned by frame number)

     Note: The FACCH gets the same bandwith (8 half bursts) as in TCH/F, in the
           middle of the transmission the bandwith doubles so only 6 bursts are
       needed. In this scheme, the FACCH replaces two TCH/H speech frames,
       which also means that one block less is generated for higher layers.
       This eventually leads also to one measurement result less.

               m       x        m
     ...T T  T T F F F F  T T T T...
          ...T T T T F F  F F T T T T...
                   m        m       m
     (measurement values positioned by point in time)

What confuses me the most in osmo-bts is that the ongoing_facch flag is set after the FACCH is
generated. I would expect this condition somewehere in between. But maybe I am overlooking
something here.

There also a completely different question that came up: Is it even allowed to replace a SUB frame
with a FACCH?

However, maybe its better to review the patches first to see what makes sense here and how it can
be improved. It would also good to know if the above is correct. (important: the "M" markers
indicate the location of the frame number from the beginning of the frame.)

#11 Updated by fixeria about 1 month ago

4323

Hi Philipp,

as promised, I am attaching my old paintings that I used while working on TCH/H support for trxcon. They're quite draftish and inaccurate, but should shed some light on how FACCH/H decoding is done in both osmo-bts-trx and trxcon. The problem is that in osmo-bts-trx we're still sending only one BFI (see step 'f'). An additional BFI needs to be sent (in speech mode) when the buffer contains a complete FACCH/H frame (see steps 'c' or 'd'). This way we keep the frame rate: one frame on each 2nd received burst. I can write a patch quickly.

Kind regards,
Vadim.

#12 Updated by dexter about 1 month ago

  • % Done changed from 40 to 60

fixeria and me have discussed some of the problems of the TCH/H and the measurement processing (thanks for the scan of your notes!) We decided not to use the approach proposed in #20840 (count FACCH blocks twice.) We think that measurement.c should detect and handle measurements coming from FACCH.

The patch that prevents measurement (RSSI) values attached to the BFI (fake TCH) indication is still in review:
https://gerrit.osmocom.org/c/osmo-bts/+/20841 sched_lchan_tchf: count measurements for FACCH/F only once

Then there was a small bug in the SUB frame detection logic, which I corrected now:
https://gerrit.osmocom.org/c/osmo-bts/+/20852 measurement: count all blocks as SUB for TCH/F in signalling mode

Since the amount of measuremnt values and sub frames is indeed different depending on the channel mode, I fixed this as well.
https://gerrit.osmocom.org/c/osmo-bts/+/20853 measurement: fix expected number of measurements

Not yet fixed is the problem we have when a FACCH is injected into an TCH/H channel. If this happens, and a sub frame is hit the results get messed up. This is why TC_meas_res_speech_tchh_facch does not yet pass. I still wonder if it is even legal to take out a voice frame for a FACCH frame. I wouln't be surprised if this would be forbidden.

I would now do the following: If a FACCH is received, the two BFI indications will not carry RSSI values and because of this only the FACCH measurement value is in the list. When the measurement logic counts out the measurements it will detect that there were FACCH frames and make sure that this taken into account properly (expect less sub measurements, expect less measurements in total, don't compensate missing measurements.)

#13 Updated by dexter 26 days ago

Sorting out the remaining problems with TC_meas_res_speech_tchh_facch is actually not that easy. My original idea was to add code to measurement.c that accounts the FACCH measurement samples differently so that the one less measurement sample that is generated when the FACCH is transmitted is taken into account when doing the measuremnt calculations. Unfortunately this did not work out.

(I am still not getting smart out of the frame numbers that mark the beginning of the FACCH. The FACCH has the same frame number as one of the the BFI TCH samples. This does not match the theory, I will check with sysmobts tomorrow to see if the frame numbers look different there.)

See also: https://gerrit.osmocom.org/c/osmo-bts/+/20980

fixeria had a nice idea, which I probably did not understand correctly, but I think we are on the right way here. If we are in SPEECH mode, we will not use the FACCH to get the measurement samples. Instead we will only use the generated TCH indications. This way the stream of measurement samples is evened out. For TCH/F it is not a problem anyway because FACCH and voice blocks have the same length. The problem only manifests itself in TCH/H, where FACCH and voice blocks have different length. With the current version of my patch TC_meas_res_speech_tchh_facch is passing.

See also: https://gerrit.osmocom.org/c/osmo-bts/+/21024

#14 Updated by dexter 5 days ago

I have now analyzed and compared with the behavior we see with osmo-bts-sysmo. With osmo-bts-sysmo I find the same behavior for TCH/F as we currently have it in osmo-bts-trx, but on TCH/H the behavior is different. On osmo-bts-sysmo, the phy seems to mask out the one missing TCH measurement, which seems logical to me because it makes the calculation much easier. For osmo-bts-trx the behavior looks completely messed up (see report below).


Behavior of the sysmobts-phy
=========================================================================================================

=============
== FACCH/F ==
=============

---------8<--------- sysmo_bts_tch_f_facch.log ---------8<---------
===================> GOT MEAS: TCH,   fn=0
===================> GOT MEAS: TCH,   fn=4
===================> GOT MEAS: FACCH, fn=8
<0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg EST_IND from LAPDm to A-bis
===================> GOT MEAS: TCH,   fn=13
<000e> l1sap.c:143 (bts=0,trx=0,ts=1,ss=0) RTP clock out of sync with lower layer: 320 vs 160 (15084->15093)
===================> GOT MEAS: TCH,   fn=17
===================> GOT MEAS: TCH,   fn=21
===================> GOT MEAS: TCH,   fn=26

....

===================> GOT MEAS: TCH,   fn=30
===================> GOT MEAS: TCH,   fn=34
===================> GOT MEAS: FACCH, fn=39
<0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg DATA_IND from LAPDm to A-bis
<0000> rsl.c:3098 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) ss=0 Rx RSL DEACTIVATE_SACCH
<0006> l1sap.c:1813 (bts=0,trx=0,ts=0,ss=0) deactivating sacch chan_nr=SDCCH/4(0) on TS0 trx=0
<0006> oml.c:1584 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.req (SACCH TxDL)
<0007> l1_if.c:167 Tx L1 prim MPH-DEACTIVATE.req
===================> GOT MEAS: TCH,   fn=43
<000e> l1sap.c:143 (bts=0,trx=0,ts=1,ss=0) RTP clock out of sync with lower layer: 320 vs 160 (15114->15123)
<0006> oml.c:1523 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.conf (SACCH TxDL)
<0006> oml.c:1584 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.req (SACCH RxUL)
<0007> l1_if.c:167 Tx L1 prim MPH-DEACTIVATE.req
<0006> oml.c:1523 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.conf (SACCH RxUL)
===================> GOT MEAS: TCH,   fn=47
===================> GOT MEAS: TCH,   fn=52
===================> GOT MEAS: TCH,   fn=56
--------------------------------8<---------------------------------

TCH   = T
FACCH = F (Half FACCH, Half TCH/VOICE)
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

------------||------------------------------------------------------------------------------------------
TTTTTTTTFFFFIFFFFTTTTTTTTSTTTTTTTTTTTTIFFFFFFFFTTTTSTTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTTTTTITTTTTTTTTTTTS
M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M

Possible slots to transmit a FACCH (same for uplink and downlink)
M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M-------
----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M---

==> Theory matches observation. There is no BFI indication whatsover for the lost TCH block. The FACCH
    block replaces the TCH block. Measurement results come exactly as if there would be no FACCH
    occurrence.

=============
== FACCH/H ==
=============

---------8<--------- sysmo_bts_tch_f_facch.log ---------8<---------
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=1359, inv_rssi=114, fn=82
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=114, fn=86
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=114, fn=91
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=114, fn=95
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=1491, inv_rssi=113, fn=99
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=113, fn=0
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=2017, inv_rssi=52, fn=4
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=43, fn=8
<0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg EST_IND from LAPDm to A-bis
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=1140, inv_rssi=41, fn=13
<000e> l1sap.c:143 (bts=0,trx=0,ts=1,ss=0) RTP clock out of sync with lower layer: 320 vs 160 (81332->81341)
<0007> l1sap.c:1348 081351/61/23/06/43 Lost SACCH block, faking meas reports and ms pwr
<0005> paging.c:663 Removed paging record, queue_len=0
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=17
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=21
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=40, fn=26
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=40, fn=30
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=34
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=50, fn=39
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=46, fn=43
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=47
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=52
<0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg DATA_IND from LAPDm to A-bis
<0000> rsl.c:3098 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) ss=0 Rx RSL DEACTIVATE_SACCH
<0006> l1sap.c:1814 (bts=0,trx=0,ts=0,ss=0) deactivating sacch chan_nr=SDCCH/4(0) on TS0 trx=0
<0006> oml.c:1584 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.req (SACCH TxDL)
<0007> l1_if.c:167 Tx L1 prim MPH-DEACTIVATE.req
<0006> oml.c:1523 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.conf (SACCH TxDL)
<0006> oml.c:1584 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.req (SACCH RxUL)
<0007> l1_if.c:167 Tx L1 prim MPH-DEACTIVATE.req
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=1184, inv_rssi=44, fn=56
<000e> l1sap.c:143 (bts=0,trx=0,ts=1,ss=0) RTP clock out of sync with lower layer: 320 vs 160 (81375->81384)
<0006> oml.c:1523 (bts=0,trx=0,ts=0,ss=0) MPH-DEACTIVATE.conf (SACCH RxUL)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=60
<0000> rsl.c:3036 (bts=0,trx=0,ts=0,ss=0) Rx RSL PAGING_CMD
<0005> paging.c:225 Add paging to queue (group=1, queue_len=1)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=65
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=47, fn=69
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=52, fn=73
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=52, fn=78

--------------------------------8<---------------------------------

TCH   = T
FACCH = F for subchannel 0 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
FACCH = f for subchannel 1 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

interval start                                                                              interval end
|------------------------------------------------------------------------------------------------------|
TtTtTtTtFtFtSFtFtFtFtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsFtFtFtFtFtFtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTts
M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M    

M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -
- -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -

==> Theory matches observation, but apparently the PHY masks the missing TCH measuremnt. Since one
    FACCH block is distributed over 6 bursts it will take out two TCH/VOICE blocks. This means we
    should get one measuremment sample less.

Behavior of the osmo-btx-trx
=========================================================================================================

=============
== FACCH/F ==
=============

---------8<--------- osmo_bts_trx_tch_f_facch.log ---------8<---------
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=10000, inv_rssi=98, fn=21
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061589/46/21/32/45 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=10000, ta_offs=0, ci=0.00, is_sub=0, rssi=-98), num_ul_meas=22, fn_mod=21
Mon Nov 23 15:42:23 2020 <0007> sched_lchan_tchf.c:220 061601/46/07/44/05 (bts=0,trx=0,ts=1) TCH/F: Received bad data (33/104)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=10000, inv_rssi=99, fn=26
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061594/46/00/37/50 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=10000, ta_offs=0, ci=0.00, is_sub=0, rssi=-99), num_ul_meas=23, fn_mod=26
Mon Nov 23 15:42:23 2020 <0007> sched_lchan_tchf.c:220 061605/46/11/48/09 (bts=0,trx=0,ts=1) TCH/F: Received bad data (37/104)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=5026, inv_rssi=55, fn=30
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061598/46/04/41/02 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=5026, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=24, fn_mod=30
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=34
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061602/46/08/45/06 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-14, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=25, fn_mod=34
Mon Nov 23 15:42:23 2020 <0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg EST_IND from LAPDm to A-bis
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=39
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061607/46/13/50/11 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=26, fn_mod=39
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=43
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061611/46/17/03/15 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=27, fn_mod=43
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=47
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061615/46/21/07/19 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=28, fn_mod=47
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=52
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061620/46/00/12/24 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=1, rssi=-55), num_ul_meas=29, fn_mod=52
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=56
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061624/46/04/16/28 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=1, rssi=-55), num_ul_meas=30, fn_mod=56
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=60
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061628/46/08/20/32 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=31, fn_mod=60
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=65
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061633/46/13/25/37 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-14, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=32, fn_mod=65
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=69
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061637/46/17/29/41 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-14, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=33, fn_mod=69
Mon Nov 23 15:42:23 2020 <0007> sched_lchan_xcch.c:116 061648/46/02/40/00 (bts=0,trx=0,ts=0) SDCCH/4(0): Received bad data (40/102)
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061645/46/25/37/49 (bts=0,trx=0,ts=0,ss=0) adding measurement (ber10k=10000, ta_offs=0, ci=0.00, is_sub=1, rssi=-97), num_ul_meas=0, fn_mod=37
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=73
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061641/46/21/33/45 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=34, fn_mod=73
Mon Nov 23 15:42:23 2020 <0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg EST_IND from LAPDm to A-bis
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=78
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061646/46/00/38/50 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-14, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=35, fn_mod=78
Mon Nov 23 15:42:23 2020 <0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg DATA_IND from LAPDm to A-bis
Mon Nov 23 15:42:23 2020 <0000> rsl.c:3098 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) ss=0 Rx RSL DEACTIVATE_SACCH
Mon Nov 23 15:42:23 2020 <0006> scheduler.c:1025 Deactivating SACCH/4(0) on trx=0 ts=0
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=82
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061650/46/04/42/02 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=36, fn_mod=82
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=86
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061654/46/08/46/06 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=37, fn_mod=86
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=91
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061659/46/13/00/11 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=38, fn_mod=91
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=55, fn=95
Mon Nov 23 15:42:23 2020 <0004> measurement.c:347 061663/46/17/04/15 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=-13, ci=0.00, is_sub=0, rssi=-55), num_ul_meas=39, fn_mod=95
--------------------------------8<---------------------------------

TCH   = T
FACCH = F (Half FACCH, Half TCH/VOICE)
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

------------||------------------------------------------------------------------------------------------
TTTTTTTTTTTTITTTTTTTTTTTTSTTTTTTTTFFFFIFFFFTTTTTTTTSTTTTTTTTTTTTITTTTTTTTFFFFSFFFFFFFFTTTTITTTTTTTTTTTTS
M   M   M    M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   M

Possible slots to transmit a FACCH (same for uplink and downlink)
M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M-------
----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M--- ----M------- M-------M---

fn=30: Measurement from TCH before FACCH (overlaps half with the FACCH)
fn=34: Measurement from FACCH (overlaps with adjacent TCH)
fn=39: Messurement from TCH after FACCH (overlaps half with the FACCH)

fn=69: Measurement from TCH before FACCH (overlaps half with the first FACCH)
fn=73: Measurement from first FACCH (overlaps half with second FACCH and adjacent TCH)
fn=78: Measurement from second FACCH (overlaps half with first FACCH and adjacent TCH)
fn=82: Measurement from TCH after FACCH (overlaps half with second FACCH)

==> Theory matches observation. The FACCH block replaces the TCH block. Measurement results come
    exactly as if there would be no FACCH occurrence. Behavior matches exactly what we also can see
    with the sysmo-bts phy.

=============
== FACCH/H ==
=============

---------8<--------- osmo_bts_trx_tch_h_facch.log ---------8<---------
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=91
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032539/24/13/01/27 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=3, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=2, fn_mod=91
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=99
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032547/24/21/09/35 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=3, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=3, fn_mod=99
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=0
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032552/24/00/14/40 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=1, rssi=-45), num_ul_meas=4, fn_mod=0
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=4
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032556/24/04/18/44 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=1, rssi=-45), num_ul_meas=5, fn_mod=4
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=8
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032560/24/08/22/48 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=3, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=6, fn_mod=8
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=13
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032565/24/13/27/01 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=3, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=7, fn_mod=13
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=17
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032569/24/17/31/05 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=8, fn_mod=17
Mon Nov 23 16:22:15 2020 <0007> sched_lchan_xcch.c:116 032578/24/00/40/14 (bts=0,trx=0,ts=0) SDCCH/4(0): Received bad data (40/102)
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032575/24/23/37/11 (bts=0,trx=0,ts=0,ss=0) adding measurement (ber10k=10000, ta_offs=0, ci=0.00, is_sub=1, rssi=-97), num_ul_meas=0, fn_mod=37
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=21
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032573/24/21/35/09 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=9, fn_mod=21
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=26
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032578/24/00/40/14 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=10, fn_mod=26
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=26
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032578/24/00/40/14 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=11, fn_mod=26
Mon Nov 23 16:22:15 2020 <0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg EST_IND from LAPDm to A-bis
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=30
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032582/24/04/44/18 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=12, fn_mod=30
Mon Nov 23 16:22:15 2020 <0000> rsl.c:3036 (bts=0,trx=0,ts=0,ss=0) Rx RSL PAGING_CMD
Mon Nov 23 16:22:15 2020 <0009> pcu_sock.c:875 PCU socket not connected, dropping message
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=34
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032586/24/08/48/22 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=13, fn_mod=34
Mon Nov 23 16:22:15 2020 <0000> rsl.c:3003 (bts=0,trx=0,ts=1,ss=0) Fwd RLL msg DATA_IND from LAPDm to A-bis
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=39
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032591/24/13/02/27 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=14, fn_mod=39
Mon Nov 23 16:22:15 2020 <0000> rsl.c:3098 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) ss=0 Rx RSL DEACTIVATE_SACCH
Mon Nov 23 16:22:15 2020 <0006> scheduler.c:1025 Deactivating SACCH/4(0) on trx=0 ts=0
Mon Nov 23 16:22:15 2020 <0006> scheduler_trx.c:279 FN timer expire_count=2: We missed 1 timers
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=47
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032599/24/21/10/35 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=15, fn_mod=47
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=52
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032604/24/00/15/40 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=1, rssi=-44), num_ul_meas=16, fn_mod=52
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=56
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032608/24/04/19/44 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=1, rssi=-44), num_ul_meas=17, fn_mod=56
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=60
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032612/24/08/23/48 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=3, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=18, fn_mod=60
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=65
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032617/24/13/28/01 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=19, fn_mod=65
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=69
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032621/24/17/32/05 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=0, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=20, fn_mod=69
Mon Nov 23 16:22:15 2020 <0007> sched_lchan_xcch.c:116 032629/24/25/40/13 (bts=0,trx=0,ts=0) SDCCH/4(0): Received bad data (91/102)
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032626/24/22/37/10 (bts=0,trx=0,ts=0,ss=0) adding measurement (ber10k=10000, ta_offs=0, ci=0.00, is_sub=1, rssi=-97), num_ul_meas=1, fn_mod=88
Mon Nov 23 16:22:15 2020 <0004> measurement.c:293 (bts=0,trx=0,ts=0,ss=0) meas period end fn:32626, fn_mod:88, status:1, pchan:CCCH+SDCCH4
Mon Nov 23 16:22:15 2020 <0004> measurement.c:580 (bts=0,trx=0,ts=0,ss=0) Calculating measurement results for physical channel: CCCH+SDCCH4
Mon Nov 23 16:22:15 2020 <0004> measurement.c:603 (bts=0,trx=0,ts=0,ss=0) Received 2 UL measurements, expected 3
Mon Nov 23 16:22:15 2020 <0004> measurement.c:664 (bts=0,trx=0,ts=0,ss=0) Received UL measurements contain 2 SUB measurements, expected 3
Mon Nov 23 16:22:15 2020 <0004> measurement.c:672 (bts=0,trx=0,ts=0,ss=0) Replaced 1 measurements with dummy values, from which 1 were SUB measurements
Mon Nov 23 16:22:15 2020 <0004> measurement.c:723 (bts=0,trx=0,ts=0,ss=0) Computed TA256(   0) BER-FULL(100.00%), RSSI-FULL(- 97dBm), BER-SUB(100.00%), RSSI-SUB(- 97dBm)
Mon Nov 23 16:22:15 2020 <0004> measurement.c:738 (bts=0,trx=0,ts=0,ss=0) UL MEAS RXLEV_FULL(13), RXLEV_SUB(13), RXQUAL_FULL(7), RXQUAL_SUB(7), num_meas_sub(3), num_ul_meas(3)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=73
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032625/24/21/36/09 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=0, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=21, fn_mod=73
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=78
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032630/24/00/41/14 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=22, fn_mod=78
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=78
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032630/24/00/41/14 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=23, fn_mod=78
Mon Nov 23 16:22:15 2020 <0011> lapd_core.c:1572 ((bts=0,trx=0,ts=1,ss=0)[DCCH][0]) N(S) sequence error: N(S)=0, V(R)=1 (state LAPD_STATE_MF_EST)
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=82
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032634/24/04/45/18 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=24, fn_mod=82
Mon Nov 23 16:22:15 2020 <0004> measurement.c:347 032564/24/12/26/00 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=1, rssi=-44), num_ul_meas=25, fn_mod=12
Mon Nov 23 16:22:15 2020 <0004> measurement.c:293 (bts=0,trx=0,ts=1,ss=0) meas period end fn:32564, fn_mod:90, status:1, pchan:TCH/H
Mon Nov 23 16:22:15 2020 <0004> measurement.c:580 (bts=0,trx=0,ts=1,ss=0) Calculating measurement results for physical channel: TCH/H
Mon Nov 23 16:22:15 2020 <0004> measurement.c:603 (bts=0,trx=0,ts=1,ss=0) Received 26 UL measurements, expected 25
Mon Nov 23 16:22:15 2020 <0004> measurement.c:606 (bts=0,trx=0,ts=1,ss=0) Received 1 excess UL measurements
Mon Nov 23 16:22:15 2020 <0004> measurement.c:664 (bts=0,trx=0,ts=1,ss=0) Received UL measurements contain 5 SUB measurements, expected 5
Mon Nov 23 16:22:15 2020 <0004> measurement.c:672 (bts=0,trx=0,ts=1,ss=0) Replaced 0 measurements with dummy values, from which 0 were SUB measurements
Mon Nov 23 16:22:15 2020 <0004> measurement.c:723 (bts=0,trx=0,ts=1,ss=0) Computed TA256(   1) BER-FULL( 0.00%), RSSI-FULL(- 44dBm), BER-SUB( 0.00%), RSSI-SUB(- 44dBm)
Mon Nov 23 16:22:15 2020 <0004> measurement.c:738 (bts=0,trx=0,ts=1,ss=0) UL MEAS RXLEV_FULL(63), RXLEV_SUB(63), RXQUAL_FULL(0), RXQUAL_SUB(0), num_meas_sub(5), num_ul_meas(25)
Mon Nov 23 16:22:15 2020 <0004> l1sap.c:1224 (bts=0,trx=0,ts=1,ss=0) increasing radio link timeout counter S=31 -> 32
Mon Nov 23 16:22:15 2020 <0000> rsl.c:2977 (bts=0,trx=0,ts=1,ss=0) Handing RLL msg UNIT_DATA_IND from LAPDm to MEAS REP
Mon Nov 23 16:22:15 2020 <0000> rsl.c:2885 (bts=0,trx=0,ts=1,ss=0) chan_num:17 Tx MEAS RES valid(2), flags(07)
Mon Nov 23 16:22:15 2020 <0000> rsl.c:2902 (bts=0,trx=0,ts=1,ss=0) Send Meas RES: NUM:1, RXLEV_FULL:63, RXLEV_SUB:63, RXQUAL_FULL:0, RXQUAL_SUB:0, MS_PWR:56, UL_TA:0, L3_LEN:18, TimingOff:0
Mon Nov 23 16:22:15 2020 <0006> scheduler_trx.c:279 FN timer expire_count=2: We missed 1 timers
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=91
Mon Nov 23 16:22:16 2020 <0004> measurement.c:347 032643/24/13/03/27 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=2, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=0, fn_mod=91
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=44, fn=95
Mon Nov 23 16:22:16 2020 <0004> measurement.c:347 032647/24/17/07/31 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=0, ci=0.00, is_sub=0, rssi=-44), num_ul_meas=1, fn_mod=95
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=45, fn=99
Mon Nov 23 16:22:16 2020 <0004> measurement.c:347 032651/24/21/11/35 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=0, rssi=-45), num_ul_meas=2, fn_mod=99
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=1,ss=0), ber10k=0, inv_rssi=46, fn=0
Mon Nov 23 16:22:16 2020 <0004> measurement.c:347 032656/24/00/16/40 (bts=0,trx=0,ts=1,ss=0) adding measurement (ber10k=0, ta_offs=1, ci=0.00, is_sub=1, rssi=-46), num_ul_meas=3, fn_mod=0
--------------------------------8<---------------------------------

TCH   = T
FACCH = F for subchannel 0 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
FACCH = f for subchannel 1 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

interval start                                                                              interval end
|------------------------------------------------------------------------------------------------------|
TtTtTtTtTtTtSTtTtTtTtTtTtsFtFtFtFtFtFtSFtFtFtFtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsFtFtFtFtFtFtSTtTtTtTtTtTts
M   M   M   MM   M   M    M   M   M    M   ?   M    M   M   M    M   M   M    M   M   ?    M   M   M    
                          M       M                                           M
                          ?       ?

M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -
- -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -

==> Theory and observation do not match! The measurements for the FACCH blocks do have correct frame
    numbers but there is a second TCH measurement with the same frame number but it is technically
    impossible that a TCH block finishes at the exact same position where a FACCH begins. Also we miss
    a mesaurement in the last third of the FACCH transmission, technically this position is the
    beginnning of the recurring TCH and we should get a measurement with at this position. In the

#15 Updated by dexter 5 days ago

There is good news. I had another look at the problem and this time I think I found the root cause:


=============
== FACCH/H ==
=============

===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=52
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001612/01/00/31/24 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=1, rssi=-100), num_ul_meas=4, fn_mod=52
======================> TCH UP, fn=62, fn_begin=56
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=56
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001616/01/04/35/28 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=1, rssi=-100), num_ul_meas=5, fn_mod=56
======================> TCH UP, fn=67, fn_begin=60
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=60
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001620/01/08/39/32 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=6, fn_mod=60
======================> TCH UP, fn=71, fn_begin=65
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=65
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001625/01/13/44/37 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=7, fn_mod=65
======================> TCH UP, fn=75, fn_begin=69
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=69
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001629/01/17/48/41 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=8, fn_mod=69
======================> TCH UP, fn=80, fn_begin=73
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=73
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001633/01/21/01/45 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=9, fn_mod=73
======================> TCH UP, fn=84, fn_begin=78
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=78
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001638/01/00/06/50 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=10, fn_mod=78
======================> FACCH UP, fn=88, fn_begin=78
===================> GOT MEAS: FACCH, lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=78
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001638/01/00/06/50 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=11, fn_mod=78
======================> TCH UP (SUPRESSED), fn=88, fn_begin=82
XXXXXXXXXXXXXXXXXXX> GOT MEAS: TCH/BFI fn=82
======================> TCH UP, fn=93, fn_begin=86
===========> RESTORE!
===================> GOT MEAS: TCH,   lchan=(bts=0,trx=0,ts=5,ss=0), ber10k=0, inv_rssi=100, fn=86
Mon Nov 23 22:04:10 2020 DMEAS <0004> measurement.c:347 001646/01/08/14/06 (bts=0,trx=0,ts=5,ss=0) adding measurement (ber10k=0, ta_offs=512, ci=0.00, is_sub=0, rssi=-100), num_ul_meas=12, fn_mod=86
Mon Nov 23 22:04:10 2020 DL1C <0006> scheduler_trx.c:446 We were 1 FN faster than TRX, compensating

TCH   = T
FACCH = F for subchannel 0 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
FACCH = f for subchannel 1 (Half FACCH, Half TCH/VOICE, full FACCH in at mid transmission)
SACCH = S

          1         2         3         4         5         6         7         8         9         0
01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123
            v            v            v            v            v            v            v            v

interval start                                                                              interval end
|------------------------------------------------------------------------------------------------------|
TtTtTtTtTtTtSTtTtTtTtTtTtsTtTtTtTtTtTtSTtTtTtFtTtTtsTtTtTtTtTtTtSTtTtTtTtTtTtsFtFtFtFtFtFtSTtTtTtTtTtTts
M   M   M   MM   M   M    M   M   M    M   M   M    M   M   M    M   M   M    M   M   ?    M   M   M    
                                                                              M

M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -
- -     M -  - - - -      M - - - - -      M - - -  - -     M -  - - - -      M - - - - -      M - - -

F = FACCH
t/T = TCH
_ = Training sequnce (irrelevant)
M = Measurement
? = Missing measurement, but we expect one in this place

Note: We ignore measurement result at fn_begin=82, fn=88 as it is has been added artificially
      to test something.

                                                      (FACCH BEGIN)                       (FACCH END)                               
55      67      69      71      73      75      78      80      82      84      86      88      91      93      95
tts_STT tts_STT tts_STT tts_STT tts_STT tts_STT tts_SFF tts_SFF FFs_SFF FFs_SFF FFs_STT FFs_STT tts_STT tts_STT t ...
                                                        ------- ------- ======= ======= ------- -------
                                M                            
M               M               M               M                               ?               M               M ...

Use the ending frame numbers as reported by the log above:
              M               M               M               M                               ?               M

<---------------
Assume that FACCH is in the right position, pull other measurement results back by two...
              M               M               M                               ?               M               M

Now transform back, add FACCH from above:
tts_STT tts_STT tts_STT tts_STT tts_STT tts_STT tts_SFF tts_SFF FFs_SFF FFs_SFF FFs_STT FFs_STT tts_STT tts_STT t ...
                                                ------- ------- ======= ======= ------- -------
                                                M                            
M               M               M                               ?               M               M

If we erase the '?' measurement report everything matches up the theory. We see two erased measurements in the
results at the positions where they should be.

==> The function rx_tchh_fn uses a shift register buffer scheme that is 6 bursts deep. The problem is
    presumably that the decoding functions look at the beginning of the buffer but incoming bursts are
    added at the end. This explains why the FACCH is decoded in the right position, it fits exactly.
    The TCH blocks are decoded always decoded with a two burst position delay. If we take that into
    account we can fix the frame number problem.

I also tried a hack that fills the burst gaps wit measurements, so that the it looks just like with osmo-bts-sysmo. Then BTS_Tests.TC_meas_res_speech_tchh_facch also passes.

#16 Updated by dexter 4 days ago

  • % Done changed from 60 to 80

I have now fixed the problem with the oddly aligned frame numbers by feeding the frame number of the actual block end into the remap functions that calculate fn_begin. This means I use the frame number from two bursts before here.

I also managed to fill the resulting gap at the correct position. The behavior is now almost identical to the that what I can observe at osmo-bts-sysmo, however there seem to be no BFI indications (RSSI=0) handed up. The testcase BTS_Tests.TC_meas_res_speech_tchh_facch now passes nicely and the frame numbers look good.

See also:
https://gerrit.osmocom.org/c/osmo-bts/+/21329 sched_lchan_tchh: fix frame number and fill FACCH gap

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)