Project

General

Profile

Feature #4549

Emergency Call Priority / Pre-Emption

Added by laforge 5 months ago. Updated about 22 hours ago.

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

90%

Spec Reference:

Description

This is entrely a BSC feature. The BSC
  1. notices there is a pending emergency call (RACH request with CHREQ_T_EMERG_CALL)
  2. notices it cannot allocate a suitable TCH/F or TCH/H channel
  3. must pick any random non-emergency TCH on he same cell and terminate it
  4. assign that TCH to the MS that has send the emrergency related RACH request

As OsmoBSC currently performs channel allocation "synchronously" (i.e. within the context of the received RACH request, without any delays), this must be extended. We need to introduce a queue for asynchronous processing of RACH requests, as we hav to wait for the deactivation/re-activation of the logical channel to complete at the BTS before being able to do the IMMEDIATE ASSIGNMENT.

manual testing sidenote: OsmoMSC may not be able to process Emergency Call without SIM (no IMSI, only IMEI). This is a layer3 feature and hence should be suppored by the regular operator MSC. There are no changes / extensions on the RAN side to support this. In some jurisdictions, like Germany, emergency calls without SIM/IMSI must be rejected by the operator anyway. I'm just mentioning this for testing of emergency calls: Make sure you test them with a SIM inserted.


Checklist

  • BSC_Tests.ttcn case simulating fully loaded BTS with incoming emergency call RACH req
  • BSC logic pre-emption (see update 1)
  • manual end2end verification (with modem + coaxial cabling to BTS)
  • osmo-gsm-tester test (hand over to pespin?)

Related issues

Related to OsmoGSMTester - Feature #4543: Emergency call suport in osmo-gsm-testerFeedback05/12/2020

Related to libosmocore - Bug #4819: Wrong RLL ERR IND sent during LAPDm re-establishment proceduresNew10/19/2020

History

#1 Updated by laforge 5 months ago

  • Checklist item BSC_Tests.ttcn case simulating fully loaded BTS with incoming emergency call RACH req added
  • Checklist item BSC logic pre-emption (see update 1) added
  • Checklist item manual end2end verification (with modem + coaxial cabling to BTS) added
  • Checklist item osmo-gsm-tester test (hand over to @pespin?) added

#2 Updated by dexter 2 months ago

  • Status changed from New to In Progress

#3 Updated by dexter 2 months ago

  • % Done changed from 0 to 70

I am not entirely finished with the implementation, but I think I am very close. I have a TTCN3 test that first activates all channels on the BTS (similar to TC_chan_exhaustion) and the tries a channel request for an emergency call. This test passes, I can see how one of the occupied TCH/F gets released and as soon as there i room for a the new channel I get the Channel Activation / CHannel Activation ACK.

However, when testing on hardware things look somewhat different. Things should work, but apparantly I am still having problems to detect the various lchan types properly.

#4 Updated by dexter about 2 months ago

  • Checklist item BSC_Tests.ttcn case simulating fully loaded BTS with incoming emergency call RACH req set to Done
  • Checklist item BSC logic pre-emption (see update 1) set to Done
  • Checklist item manual end2end verification (with modem + coaxial cabling to BTS) set to Done

#5 Updated by dexter about 2 months ago

  • % Done changed from 70 to 90

The implementation is now complete and the patches are up for review. Unfortunately it turned out that due to a lack of CHANNEL MODE MODIFY functionality in osmo-bsc things were more complex as expected. The patches are now up for review.

Patches for osmo-bsc:
https://gerrit.osmocom.org/c/osmo-bsc/+/19790 lchan_fsm: merge lchan_mr_config()
https://gerrit.osmocom.org/c/osmo-bsc/+/19791 lchan_fsm: make internal functions static.
https://gerrit.osmocom.org/c/osmo-bsc/+/19792 lchan_fsm: make rsl mode-modify working again
https://gerrit.osmocom.org/c/osmo-bsc/+/19793 abis_rsl: prioritize emergency calls over regular calls

TTCN3 Testcase:
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/19794 BSC_Tests: test emergency call preemption

#6 Updated by dexter about 2 months ago

I have now worked myself through the review comments of #19792 and #19793. I hope the patches are acceptable now. Getting rid of the timer based approach also showed an increase of performance while testing.

pespin: For the integration in the tester we would need to fill up all TCH/H and TCH/F with active calls. The SDCCH channels may remain free as emergency calls get TCH channels directly. When an emergency call is made, one of the occupied TCH will be dropped. At least that is what the scenario should look like.

#7 Updated by dexter about 1 month ago

  • Assignee changed from dexter to pespin

pespin All patches are merged and TC_emerg_premption also passes in jenkins (setting the verdict in the end solved the problem, however the problem did not occur when executing the tests locally). We now need a test implementation on the tester, so I hand over this ticket to you.

#8 Updated by pespin 5 days ago

  • Related to Feature #4543: Emergency call suport in osmo-gsm-tester added

#9 Updated by pespin 5 days ago

I added a osmo-gsm-tester test to verify emergency call preemption here:
https://gerrit.osmocom.org/c/osmo-gsm-tester/+/20670 sysmocom: Introduce test to verify emergency call preemption

The test sometimes passes and sometimes doesn't. When it passes I can see from ofono point of view how the 2 MS running a normal call are dropped while the new emergency call between the other 2 MS works fine.
I'm attaching a pcap for a failing case (with dropped RTP packets).

At first glance it seems like a BSC issue (or perhaps MSC, not sure). When the new Emergency RACH request comes in, the BSC attempts to drop the SCCP conns towards the MSC:

[BSC gets Channel Required for MO Emergency call in pcap frame 5576]
BSC -> MSC: BSSMAP Clear Request (Destination Local Reference: 0x080000)
BSC <- MSC: CC Release (Destination Local Reference: 0x090000)
BSC <- MSC: BSSMAP Clear Command (Destination Local Reference: 0x090000)
[BSC finally sends Channel Activation to BTS, and gets a Channel Activation ACK]
BSC -> MSC: BSSMAP Clear Request (Destination Local Reference: 0x080000)  <--- REPEATED FROM ABOVE?!!!!
BSC -> MSC: BSSMAP Clear Complete (Destination Local Reference: 0x080000)
BSC <- MSC: SCCP RLSD (Source Local Reference: 0x080000, Destination Local Reference: 0x090000)

#10 Updated by pespin 5 days ago

Looking further at the pcap trace the issue seems to happen much later though, when the emergency call is trying to be established. The MS seems to be answering the CC Setup with a Call Confirmed (frame 8819), and then MSC sends an Assignment Request to BSC (frame 8829) which after a while is rejected with an BSSMAP Assignment Failure (frame 9413). Looking at BSC logs:

20201015184804006 DCHAN <000f> fsm.c:322 lchan(0-0-2-TCH_F-0)[0x612000005320]{WAIT_RLL_RTP_ESTABLISH}: Timeout of T3101
20201015184804006 DCHAN <000f> lchan_fsm.c:1557 lchan(0-0-2-TCH_F-0)[0x612000005320]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Handling failure, will then transition to state WAIT_RF_RELEASE_ACK
20201015184804007 DCHAN <000f> lchan_fsm.c:81 lchan(0-0-2-TCH_F-0)[0x612000005320]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) lchan allocation failed in state WAIT_RLL_RTP_ESTABLISH: Timeout
20201015184804007 DCHAN <000f> lchan_fsm.c:116 lchan(0-0-2-TCH_F-0)[0x612000005320]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Signalling Assignment FSM of error (lchan allocation failed in state WAIT_RLL_RTP_ESTABLISH: Timeout)
20201015184804007 DAS <0011> lchan_fsm.c:1557 assignment(msc0-conn12_subscr-IMSI-901700000023847-TMSI-0x35a6a33d_0-0-2-TCH_F-0)[0x612000000520]{WAIT_RR_ASS_COMPLETE}: Received Event ASSIGNMENT_EV_LCHAN_ERROR
20201015184804007 DAS <0011> assignment_fsm.c:772 assignment(msc0-conn12_subscr-IMSI-901700000023847-TMSI-0x35a6a33d_0-0-2-TCH_F-0)[0x612000000520]{WAIT_RR_ASS_COMPLETE}: (bts=0,trx=0,ts=2,ss=0) Assignment failed in state WAIT_RR_ASS_COMPLETE, cause RADIO INTERFACE MESSAGE FAILURE: Failed to activate lchan (bts=0,trx=0,ts=2,ss=0)
20201015184804007 DAS <0011> assignment_fsm.c:772 assignment(msc0-conn12_subscr-IMSI-901700000023847-TMSI-0x35a6a33d_0-0-2-TCH_F-0)[0x612000000520]{WAIT_RR_ASS_COMPLETE}: (bts=0,trx=0,ts=2,ss=0) incrementing rate counter: assignment:error Assignment failed for other reason
20201015184804007 DMSC <0007> osmo_bsc_sigtran.c:378 Tx MSC: BSSMAP: ASSIGNMENT FAIL

#11 Updated by dexter 1 day ago

I have tested the functionality of the emergency calling preemption again on my test network. This time my setup has two TCH/F channels and an asterisk backend. I can make two calls to numbers which play recordings (so I do not need to worry about MO/MT, all calls are MT). When I make another call to a recording one of the running calls gets cancelled. This works fine so far.

I was able to reproduce the problem with the duplicated CLEAR REQUEST. I also see a CLEAR REQUEST two times. Since I did manual testing this slipped through because everything else looked ok. The problem is in bsc_subscr_conn_fsm.c. I would expect the gscon fsm to change to the clearing state once it has sent the first clear request but the problem could also be at the MSC as well.

Here is the log from my setup:

First CLEAR REQUEST is when the lchan gets detached, this should be the first and only time where a CLEAR REQUEST is sent.

Sun Oct 18 22:40:50 2020 DCHAN <000f> lchan_fsm.c:1595 lchan(0-0-1-TCH_F-0)[0x562c1c1a0d20]{ESTABLISHED}: state_chg to WAIT_RF_RELEASE_ACK
Sun Oct 18 22:40:50 2020 DMSC <0007> bsc_subscr_conn_fsm.c:774 SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0]{ACTIVE}: conn detaches lchan lchan(0-0-1-TCH_F-0)[0x562c1c1a0d20]
Sun Oct 18 22:40:50 2020 DCHAN <000f> bsc_subscr_conn_fsm.c:778 lchan(0-0-1-TCH_F-0)[0x562c1c1a0d20]{WAIT_RF_RELEASE_ACK}: conn SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0] detaches lchan (primary lchan)
Sun Oct 18 22:40:50 2020 DMSC <0007> bsc_subscr_conn_fsm.c:157 SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0]{ACTIVE}: Tx BSSMAP CLEAR REQUEST(EQUIPMENT FAILURE) to MSC
Sun Oct 18 22:40:50 2020 DMSC <0007> osmo_bsc_sigtran.c:379 Tx MSC: BSSMAP: CLEAR REQUEST

Here seems to come an MT_DTAP from the MSC, which causes another CLEAR_REQUEST. When I rethink this it might be also the MSC that is behaving wrongly. Is it still permitted to send MT_DTAP messages to the BSC when it has asked for clearing the connection? Maybe the MSC should block those messages and continue with the clearing?

Sun Oct 18 22:40:50 2020 DMSC <0007> osmo_bsc_bssap.c:1266 SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0]{ACTIVE}: Received Event MT_DTAP
Sun Oct 18 22:40:50 2020 DMSC <0007> bsc_subscr_conn_fsm.c:1118 subscr-IMSI-001010000000101-TMSI-0x96263ae7 Called submit dtap without an lchan.
Sun Oct 18 22:40:50 2020 DMSC <0007> bsc_subscr_conn_fsm.c:1155 SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0]{ACTIVE}: Tx BSSMAP CLEAR REQUEST to MSC
Sun Oct 18 22:40:50 2020 DMSC <0007> bsc_subscr_conn_fsm.c:157 SUBSCR_CONN(msc0-conn19_subscr-IMSI-001010000000101-TMSI-0x96263ae7)[0x562c1c1b5cf0]{ACTIVE}: Tx BSSMAP CLEAR REQUEST(EQUIPMENT FAILURE) to MSC
Sun Oct 18 22:40:50 2020 DMSC <0007> osmo_bsc_sigtran.c:379 Tx MSC: BSSMAP: CLEAR REQUEST

In the second problem you describe I guess something took too long. "Timeout of T3101" sounds not good. I wonder where to look in the pcap. The packet numbers seem not to match up. When I get you right this is an additional problem and the emergency call fails completely. It would be good to have the full log of this situation.

#12 Updated by pespin 1 day ago

Attaching osmo-gsm-tester output (tar.bz2) with all logs, configs, etc. together with a pcap files taken with tcpdump on the main unit (removed TRXD and RTP).

So to clarify there's (at least) 2 different issues:
1- Duplicated BSSMAP Clear Request BSC->MSC
2- Asignment Failure answered by BSC upon Assignment Request by MSC of the MT side of the emergency call (forwarded to an MS).

Regarding 2, I guess it due to the second lef of the previous non-emergency call is not released, meaning there's only 1 TS freed which is then use by the MO side of the emergency call. Then we still need to free some TS space for the MT side in this case.

#13 Updated by pespin 1 day ago

A bit before the "BSSMAP Assignemtn Failure" being sent BSC->MSC for the MT leg of the preemptive emergency call, I see 2 suspcious things:
  • BTS sending an "ERROR INDication" to BSC with cause: "Cause: SABM frame with information not allowed in this state (14)".
  • The MS sending to the BTS in lapdm: "Assignment Failure" with cause "RR cause value: Protocol error unspecified (111)". But the BTS doesn't seem to be forwarding this to the BSC somehow.

#14 Updated by pespin 1 day ago

Logs related to the SABM issue (ERROR IND):

20201019124504787 DLLAPD <0011> lapd_core.c:909 ((bts=0,trx=0,ts=0,ss=0)[DCCH][0]) SABM not allowed during contention resolution (state=LAPD_STATE_TIMER_RECOV)
20201019124504787 DLLAPD <0011> lapd_core.c:426 ((bts=0,trx=0,ts=0,ss=0)[DCCH][0]) sending MDL-ERROR-IND cause 14 from state LAPD_STATE_TIMER_RECOV
20201019124504787 DLLAPD <0011> lapdm.c:550 ((bts=0,trx=0,ts=0,ss=0)[DCCH][0]) sending MDL-ERROR-IND 14
20201019124504787 DRSL <0000> rsl.c:3003 (bts=0,trx=0,ts=0,ss=0) Fwd RLL msg ERROR_IND from LAPDm to A-bis

#15 Updated by pespin 1 day ago

And the lapdm uplink "Assignment failure" seems to be not forwarded due to:

20201019124505022 DLLAPD <0011> lapd_core.c:1506 ((bts=0,trx=0,ts=0,ss=0)[DCCH][0]) N(S) sequence error: N(S)=0, V(R)=2 (state LAPD_STATE_TIMER_RECOV)

#16 Updated by laforge about 23 hours ago

pespin wrote:

A bit before the "BSSMAP Assignemtn Failure" being sent BSC->MSC for the MT leg of the preemptive emergency call, I see 2 suspcious things:
  • BTS sending an "ERROR INDication" to BSC with cause: "Cause: SABM frame with information not allowed in this state (14)".
  • PCAP file packet 3659: This SABM is received on the TS0/sdcch-0.
  • If you use the wireshark-mate rules from git.osmocom.org/wireshark-mate.git, this will be mate.rsl_lchan == 6
    • channel activated in 1327
    • CM service request for MO call in 1338
    • CC SETUP for MO call in 1371
    • SACCH deactivated in 1440
    • RF CHAN REL in 1566 + ACK in 1569

So as the lchan is deactivated, why do we get a SABM fram in uplink on that lchan 48 seconds later in 3595?

#17 Updated by laforge about 23 hours ago

Ok, nevermind. The same SDCCH-0 gets re-cycled is "mate.rsl_lchan == 17" in 3517.

  • 3521: CHAN ACT ACK
  • 3532: PAGING RESP
  • 3545: CC SETUP
  • 3579: CC CALL CONF
  • 3595: RR ASSIGNMENT CMD
  • 3619: RR ASSIGNMENT CMD on Um
  • 3647: RR ASSIGNMENT CMD on Um (retransmission)
  • 3659: LAPDM SABM frame in uplink on that same lchan

So it looks like the MS should be establishing LAPDm on the new TCH/F, but somehow tries it on the old channel?

To be correct, there also seems to be a bug on our side: As the contention resolution procedure has happened already at the start of the lchan in 3531/3547, it is actually legal for the MS to do a SABM at a later point in time, without any information field. This could be seen as a "re-start/re-set the connection".

#18 Updated by laforge about 23 hours ago

3GPP TS 44.006 8.4.2.1

If an SABM command is received while in the multiple-frame-established state, the data link layer entity shall proceed as follows:
  • if the SABM command carries no information field (i.e. L=0), then the data link layer entity shall conform to the re-establishment procedure described in sub-clause 8.6;

So we are clarly not doing that.

#19 Updated by laforge about 23 hours ago

3GPP TS 48.006 Section 8.6.3: Procedures for re-establishment

When the data link layer receives in the multiple frame established state or timer recovery state a DL-ESTABLISH-REQUEST primitive from layer 3 or an SABM (with L=0), the normal establishment procedure of sub-clause 8.4.1.2 shall be initiated. Any information frames in the I queue (including I frames for DL-DATA-REQUEST primitives and any received segmented layer 3 message units for which the last segment has not been received) shall be discarded.

#20 Updated by laforge about 23 hours ago

  • Related to Bug #4819: Wrong RLL ERR IND sent during LAPDm re-establishment procedures added

#21 Updated by laforge about 23 hours ago

Well, we actually do properly deal with the re-establishment
  • 3666 is the UA in response to the SABM
  • 3674 is the ASSIGNMENT FAILURE on L3 inside the re-established LAPDm

So all that seems broken here is that osmo-bts sends a RLL ERR IND even though it proceeds.

The assignment fiilure states "protocol error, unspecified" - which is of course not helpful.

#22 Updated by laforge about 22 hours ago

  • Description updated (diff)

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)