Project

General

Profile

Bug #3671

osmo-bts-sysmo and TTCN3 BTS_Tests f_est_dchan does not check for Chan Required

Added by pespin 21 days ago. Updated 13 days ago.

Status:
Feedback
Priority:
Normal
Assignee:
Category:
osmo-bts-sysmo
Target version:
-
Start date:
10/24/2018
Due date:
% Done:

0%

Spec Reference:

Description

As a result, if RACH is not received (real HW setup), some tests fail sometimes afterwards (confusing) because Assignment Command is sent BSC->BTS and BTS doesn't forward it because presumably it didn't receive the Rach Request before.

In that scenario, I don't see any Immediate Assignment BTS->MS being forwarded in GSMTAP, but I see some data being sent in lower layers.

I attach a tgz with both correct and incorrect test BTS_Tests.TC_chan_act_a53 runs. Strangely enough, I don't see any message about it being dropped/hidden from GSMTAP in bts logs.

fail:
20180901161922277 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:752 000312/00/00/06/04 Rx PH-RTS.ind chan_nr=PCH/AGCH on TS0 link_id=0x00d
20180901161922277 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:856 000312/00/00/06/04 Tx PH-DATA.req chan_nr=PCH/AGCH on TS0 link_id=0x00
20180901161922277 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/osmo-bts-sysmo/l1_if.c:459 000312/00/00/06/04 PH-DATA.req(01 06 3f 00 09 e3 64 17 01 ea 00 00 00 00 00 00 4e 63 68 00 00 00 00 )
20180901161922304 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:752 000318/00/06/12/10 Rx PH-RTS.ind chan_nr=PCH/AGCH on TS0 link_id=0x00d
20180901161922305 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:856 000318/00/06/12/10 Tx PH-DATA.req chan_nr=PCH/AGCH on TS0 link_id=0x00
20180901161922305 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/osmo-bts-sysmo/l1_if.c:459 000318/00/06/12/10 PH-DATA.req(15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b )

success:

20180901162203656 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:752 002811/02/03/06/43 Rx PH-RTS.ind chan_nr=PCH/AGCH on TS0 link_id=0x00d
20180901162203656 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:856 002811/02/03/06/43 Tx PH-DATA.req chan_nr=PCH/AGCH on TS0 link_id=0x00
20180901162203656 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/osmo-bts-sysmo/l1_if.c:459 002811/02/03/06/43 PH-DATA.req(01 06 3f 00 09 e3 64 17 10 a3 00 00 00 00 00 00 4e 63 68 00 00 00 00 )
20180901162203683 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:752 002817/02/09/12/01 Rx PH-RTS.ind chan_nr=PCH/AGCH on TS0 link_id=0x00d
20180901162203684 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/common/l1sap.c:856 002817/02/09/12/01 Tx PH-DATA.req chan_nr=PCH/AGCH on TS0 link_id=0x00
20180901162203684 DL1P <0007> /home/pespin/dev/sysmocom/git/osmo-bts/src/osmo-bts-sysmo/l1_if.c:459 002817/02/09/12/01 PH-DATA.req(15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b )

I tried waiting for that message in TTCN3 but it fails because apparently RSL_CCHAN is somehow attached to component "test_CT" and can only be used on functions with "runs on test_CT", but this function is already attached to "ConnHdlr".

diff --git a/bts/BTS_Tests.ttcn b/bts/BTS_Tests.ttcn
index 5b073ef..a88d02f 100644
--- a/bts/BTS_Tests.ttcn
+++ b/bts/BTS_Tests.ttcn
@@ -1353,8 +1353,7 @@ private function f_est_dchan(boolean encr_enable := false) runs on ConnHdlr {

        f_L1CTL_PARAM(L1CTL, g_pars.l1_pars.ms_actual_ta, g_pars.l1_pars.ms_power_level);
        fn := f_L1CTL_RACH(L1CTL, ra);
-       /* This arrives on CCHAN, so we cannot test for receiving CHAN RQDhere */
-       //RSL.receive(tr_RSL_CHAN_RQD(int2oct(23,1)));
+       RSL_CCHAN.receive(tr_RSL_UD(tr_RSL_CHAN_RQD(int2oct(ra,1))));

So 2 thing shere:
  • Make it possible to stop tests early during f_est_dchan if no RACH/ChanRequired is received in RSL.
  • Find out why Immediate assignment is not shown in GSMTAP when there was no RACH beforehand, and why BTS doesn't print an error in that case.
last_run_both.tgz last_run_both.tgz 490 KB pespin, 10/24/2018 07:11 PM

History

#1 Updated by pespin 20 days ago

After discussion with Daniel, the outcome on how to implement this in TTCN3 is to do something similar to ExpectData/ExpectedCreatCallback in BSSMAP_Emulation.ttcn

So when we send a RACH request, we need to register that ra with the vc_conn (ConnHdlr) in the RSL_Emulation.ttcn.

RSL_CCHAN is connected to the RSL_Emulation which then takes care of dispatching the ChanRequired to individual vc_vonn, and we can then do RSL.receive() in f_est_dchan.

#2 Updated by pespin 14 days ago

I submitted https://gerrit.osmocom.org/#/c/osmo-ttcn3-hacks/+/11562/

However, it seems to fail sometimes, as if the ConnectionTable did not contain the request (the ChanRequired sent by BTS seems good, ra and fn are the expected ones set by MS).

So I think it's race condition between adding the request to the ConnectionTable and receiving the ChanRequired. In that case.

Only solution I see is to call RSL.send(ts_RSLDC_ChanRqd(int2oct(ra,1), fn)); before fn = f_L1CTL_RACH. In that case, we need to fake/hardcode an fn and don't check the fn when we receive the ChanRequired message in RSL_Emulation.ttcn (or check against the hardcoded one).

#3 Updated by pespin 14 days ago

I confirm there's a race conditon. I addd extra logging and run some tests:

TC_rll_rel_req(394)@7457151a6e84: Rx LAPDm { ab := { addr := { spare := '0'B, lpd := 0, sapi := 0, c_r := true, ea := true }, ctrl := { u := { u := '010'B, p_f := true, u2 := '00'B, spare := '11'B } }, len := 0, m := false, el := 1, payload := ''O } }
TC_rll_rel_req-RSL(384)@7457151a6e84: PESPIN: f_cid_clear
MTC@7457151a6e84: "TC_rll_rel_req": XXX Starting { sapi := 0, link_id := { c := SACCH (1), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 }, l3 := ''O, exp := true } on { u := { sdcch4 := { tag := '001'B, sub_chan := 2 } }, tn := 0 }
TC_rll_rel_req-RSL(384)@7457151a6e84: PESPIN: f_cid_create_cnr
TC_rll_rel_req(395)@7457151a6e84: PESPIN: calling f_L1CTL_RACH 23
TC_rll_rel_req(395)@7457151a6e84: PESPIN: called with fn returned 2726
TC_rll_rel_req-RSL(384)@7457151a6e84: PESPIN: f_cid_by_ra_fn2'17'O{ t1_p := 2, t3 := 23, t2 := 22 }
TC_rll_rel_req-RSL(384)@7457151a6e84: No Dchan handler for '17'O{ t1_p := 2, t3 := 23, t2 := 22 }
TC_rll_rel_req-RSL(384)@7457151a6e84: PESPIN: Received CHAN-RQD from UNKNOWN RACH REQ{ ra := '17'O, frame_nr := { t1_p := 2, t3 := 23, t2 := 22 } }
TC_rll_rel_req-RSL(384)@7457151a6e84: PESPIN: f_cid_create '17'O2726
TC_rll_rel_req(395)@7457151a6e84: Stopping testcase execution from "BTS_Tests.ttcn":1363
MC@7457151a6e84: Test Component 395 has requested to stop MTC. Terminating current testcase execution.
MTC@7457151a6e84: Test case TC_rll_rel_req finished. Verdict: fail reason: "BTS_Tests.ttcn:1363 : Timeout waiting for CHAN-RQD from RACH REQ <23, 2726>" 
MTC@7457151a6e84: Starting external command `../ttcn3-tcpdump-stop.sh BTS_Tests.TC_rll_rel_req fail'.
------ BTS_Tests.TC_rll_rel_req fail ------

So it can be seen that CHAN-RQD is received BEFORE f_cid_create is called.

#4 Updated by pespin 13 days ago

  • Status changed from New to Feedback

I reworked the commit to register ConnHdlr for any FN for that RA, and then explictly check the FN during RSL.receive of the ChanRqd.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)