Project

General

Profile

Actions

Bug #2947

closed

OsmoMSC crashes with A5/3 configured and MS sending no Classmark 2 in LU Request

Added by neels about 6 years ago. Updated almost 6 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
02/15/2018
Due date:
% Done:

100%

Resolution:
Spec Reference:

Description

I have a 2G network set up, configured to A5/3 encryption.
My MS appears to omit the Classmark 2 in the LU request.
Hence, after successful auth, the cipher mode request cannot tell whether the MS is capable of A5/3 and rejects.

In the course of the reject, OsmoMSC crashes with a segfault -- trying to print vlr_subscr information, where the vsub is not NULL but still invalid for some reason.
Details follow.


Files

lu_no_classmark2.pcapng lu_no_classmark2.pcapng 45.4 KB neels, 02/15/2018 09:21 PM

Related issues

Related to Cellular Network Infrastructure - Bug #3043: A5/3 encryption failsResolvedneels03/08/2018

Actions
Actions #1

Updated by neels about 6 years ago

The network advertises R99 capability; the phone is a S4mini, so definitely UMTS capable. Classmark 2 is optional, but supposedly to be sent for UMTS capable networks. It's interesting to note this, but it's a valid situation and OsmoMSC should certainly not crash.

See attached pcap with gsmtap showing R99 in SI3 and successful auth response leading to the crash (gsmtap_log included)

OsmoMSC log & bt:

Thu Feb 15 21:38:59 2018 DRLL DEBUG gsm_04_08.c:3462 Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
Thu Feb 15 21:38:59 2018 DMM DEBUG gsm_04_08.c:982 IMSI:901700000014701: MM R99 AUTHENTICATION RESPONSE (res = a2764a1cfe5f6c2d)
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr.c:1088 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:142 SUBSCR(IMSI:901700000014701) received res: a2 76 4a 1c fe 5f 6c 2d 
Thu Feb 15 21:38:59 2018 DVLR INFO vlr_auth_fsm.c:179 SUBSCR(IMSI:901700000014701) AUTH established UMTS security context
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:224 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result VLR_AUTH_RES_PASSED
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:228 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:233 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:233 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(901700000014701)[0x55555594dd70]
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:233 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_AUTHENTICATED}: Freeing instance
Thu Feb 15 21:38:59 2018 DVLR DEBUG fsm.c:318 VLR_Authenticate(901700000014701)[0x555555939fb0]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_auth_fsm.c:233 vlr_lu_fsm(901700000014701)[0x55555594dd70]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr_lu_fsm.c:822 vlr_lu_fsm(901700000014701)[0x55555594dd70]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
Thu Feb 15 21:38:59 2018 DVLR DEBUG vlr.c:1123 vlr_lu_fsm(901700000014701)[0x55555594dd70]{VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode
Thu Feb 15 21:38:59 2018 DMM DEBUG gsm_04_08.c:3644 -> CIPHER MODE COMMAND IMSI:901700000014701
Thu Feb 15 21:38:59 2018 DMSC DEBUG gsm_04_08.c:120 CLASSMARK 2 unknown, assuming MS doesn't support A5/3
Thu Feb 15 21:38:59 2018 DMM ERROR gsm_04_08.c:3660 IMSI:901700000014701: cannot start ciphering, no intersection between MSC-configured and MS-supported A5 algorithms
Thu Feb 15 21:38:59 2018 DVLR ERROR vlr_lu_fsm.c:842 vlr_lu_fsm(901700000014701)[0x55555594dd70]{VLR_ULA_S_WAIT_AUTH}: Failed to send Ciphering Mode Command
Thu Feb 15 21:38:59 2018 DMM DEBUG msc_ifaces.c:118 -> CM SERVICE Reject cause: 17
Program received signal SIGSEGV, Segmentation fault.
vlr_subscr_name (vsub=0x3030303037313039) at ../../../../src/osmo-msc/src/libcommon/gsm_subscriber_base.c:46
46        if (vsub->msisdn[0])
(gdb) bt
#0  vlr_subscr_name (vsub=0x3030303037313039) at ../../../../src/osmo-msc/src/libcommon/gsm_subscriber_base.c:46
#1  0x000055555557285b in msc_tx (conn=0x55555594dfc0, msg=0x55555594d480) at ../../../../src/osmo-msc/src/libmsc/msc_ifaces.c:51
#2  0x0000555555584841 in vlr_lu_compl_fsm_failure (fi=0x55555594dd70, cause=<optimized out>) at ../../../../src/osmo-msc/src/libvlr/vlr_lu_fsm.c:350
#3  0x00007ffff7333e7f in _osmo_fsm_inst_dispatch (fi=0x55555594dd70, event=3, event@entry=21845, data=data@entry=0x7fffffffdf5c, 
    file=file@entry=0x5555555971e0 "../../../../src/osmo-msc/src/libvlr/vlr_auth_fsm.c", line=line@entry=233) at ../../../src/libosmocore/src/fsm.c:481
#4  0x00007ffff733444a in _osmo_fsm_inst_term (fi=fi@entry=0x555555939fb0, cause=cause@entry=OSMO_FSM_TERM_REGULAR, data=data@entry=0x7fffffffdf5c, 
    file=file@entry=0x5555555971e0 "../../../../src/osmo-msc/src/libvlr/vlr_auth_fsm.c", line=line@entry=233) at ../../../src/libosmocore/src/fsm.c:534
#5  0x0000555555583f83 in auth_fsm_term (fi=0x555555939fb0, res=<optimized out>) at ../../../../src/osmo-msc/src/libvlr/vlr_auth_fsm.c:233
#6  0x00007ffff7333e7f in _osmo_fsm_inst_dispatch (fi=0x555555939fb0, event=event@entry=4, data=data@entry=0x7fffffffdff0, file=file@entry=0x555555596370 "../../../../src/osmo-msc/src/libvlr/vlr.c", 
    line=line@entry=1088) at ../../../src/libosmocore/src/fsm.c:481
#7  0x000055555558210b in vlr_subscr_rx_auth_resp (vsub=<optimized out>, is_r99=is_r99@entry=true, is_utran=<optimized out>, res=res@entry=0x7fffffffe040 "\242vJ\034\376_l-j", res_len=res_len@entry=8 '\b')
    at ../../../../src/osmo-msc/src/libvlr/vlr.c:1088
#8  0x000055555556ce2e in gsm48_rx_mm_auth_resp (msg=0x555555943420, conn=0x555555943420) at ../../../../src/osmo-msc/src/libmsc/gsm_04_08.c:984
#9  gsm0408_rcv_mm (msg=0x555555943420, conn=0x555555943420) at ../../../../src/osmo-msc/src/libmsc/gsm_04_08.c:1112
#10 gsm0408_dispatch (conn=conn@entry=0x555555943420, msg=msg@entry=0x55555593a200) at ../../../../src/osmo-msc/src/libmsc/gsm_04_08.c:3493
#11 0x00005555555794ad in msc_dtap (conn=0x555555943420, link_id=<optimized out>, msg=0x55555593a200) at ../../../../src/osmo-msc/src/libmsc/osmo_msc.c:107
#12 0x0000555555562d74 in rx_dtap (scu=0x7ffff754a900 <hexd_buff>, a_conn_info=0x7fffffffe0c0, a_conn_info=0x7fffffffe0c0, msg=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/a_iface_bssap.c:600
#13 a_sccp_rx_dt (scu=scu@entry=0x5555558ea700, a_conn_info=a_conn_info@entry=0x7fffffffe0f0, msg=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/a_iface_bssap.c:622
#14 0x0000555555560f24 in sccp_sap_up (oph=0x55555593a288, _scu=0x5555558ea700) at ../../../../src/osmo-msc/src/libmsc/a_iface.c:553
#15 0x00007ffff7333e7f in _osmo_fsm_inst_dispatch (fi=0x5555558f0ed0, event=11, data=data@entry=0x555555942f30, file=file@entry=0x7ffff6cb14a8 "../../../src/libosmo-sccp/src/sccp_scoc.c", line=line@entry=1581)
    at ../../../src/libosmocore/src/fsm.c:481
#16 0x00007ffff6ca1985 in sccp_scoc_rx_from_scrc (inst=inst@entry=0x5555558e8150, xua=xua@entry=0x555555942f30) at ../../../src/libosmo-sccp/src/sccp_scoc.c:1581
#17 0x00007ffff6c9f67b in scrc_rx_mtp_xfer_ind_xua (inst=inst@entry=0x5555558e8150, xua=0x555555942f30) at ../../../src/libosmo-sccp/src/sccp_scrc.c:449
#18 0x00007ffff6ca2555 in mtp_user_prim_cb (oph=0x555555931da8, ctx=0x5555558e8150) at ../../../src/libosmo-sccp/src/sccp_user.c:176
#19 0x00007ffff6c9a393 in m3ua_rx_xfer (xua=0x5555558f36b0, asp=0x5555558c0550) at ../../../src/libosmo-sccp/src/m3ua.c:586
#20 m3ua_rx_msg (asp=asp@entry=0x5555558c0550, msg=msg@entry=0x55555592dc10) at ../../../src/libosmo-sccp/src/m3ua.c:738
#21 0x00007ffff6ca5553 in xua_cli_read_cb (conn=<optimized out>) at ../../../src/libosmo-sccp/src/osmo_ss7.c:1592
#22 0x00007ffff55bf3fb in osmo_stream_cli_read (cli=0x5555558e59a0) at ../../../src/libosmo-netif/src/stream.c:192
#23 osmo_stream_cli_fd_cb (ofd=<optimized out>, what=1) at ../../../src/libosmo-netif/src/stream.c:276
#24 0x00007ffff7330a71 in osmo_fd_disp_fds (_eset=0x7fffffffe500, _wset=0x7fffffffe480, _rset=0x7fffffffe400) at ../../../src/libosmocore/src/select.c:216
#25 osmo_select_main (polling=<optimized out>) at ../../../src/libosmocore/src/select.c:256
#26 0x000055555555f46c in main (argc=1, argv=<optimized out>) at ../../../../src/osmo-msc/src/osmo-msc/msc_main.c:533
Actions #2

Updated by laforge about 6 years ago

Whoever will fix this: Please make sure to create a TTCN-3 test case for this so we can continue to automatically test for this bug. Let's make it the last test in the testsuite to avoid the crash messing up other tests' results.

Actions #3

Updated by laforge about 6 years ago

Hi Neels,

On Thu, Feb 15, 2018 at 09:22:30PM +0000, neels [REDMINE] wrote:

The network advertises R99 capability; the phone is a S4mini, so definitely UMTS capable. Classmark 2 is optional, but supposedly to be sent for UMTS capable networks. It's interesting to note this, but it's a valid situation and OsmoMSC should certainly not crash.

Well, OsmoMSC isn't even trying to send a CLASSMARK INQUIRY, is it? IMHO, the normal procedure should be to
  • request early classmark sending in the SI
  • check if we actually received CLASSMARK CHANGE by the time we want to authenticate or cipher
    • if not, send a classmark inquiry, start a timer, wait for response

This kind of procedure is at least needed for those [old] phones that don't do early classmark sending
at all (OsmocomBB "mobile" can be configured like that, AFAIR). Not sure if it would have helped in case of
your particular issue. For sure any UMTS capable phone should be able to do early classmark sending.

In any case, if we need CM2/CM3 information and we don't have it, it is reasonable to ask the phone for it,
and if that fails use some default values or disconnect.

Actions #4

Updated by laforge about 6 years ago

  • Assignee set to neels
Actions #5

Updated by neels about 6 years ago

We don't send a Classmark Inquiry and might not even allow Classmark Change to be received (I think I dimly remember such factoid).
So your suggestions make perfect sense.

Actions #6

Updated by laforge about 6 years ago

Please make sure to add a ttcn3 testcase before fixing this

Actions #7

Updated by neels about 6 years ago

  • % Done changed from 0 to 10

In osmo-ttcn3-hacks/msc, we have a test that is very similar to the described situation: TC_lu_imsi_auth_tmsi_encr_3_1().
In fact all that is needed to trigger above segfault is to enable debug log for the 'msc' category!
i.e. a workaround for this issue is to disable debug logging for the 'msc' category ; )

About CM2: that test does send a classmark update containing CM2, to indicate that A5/3 is not supported.
The scenario described above demands that CM2 should not be known, and we should probably have a separate test for that scenario, however, CM2 presence does not influence triggering of the segfault; all that is needed is the decision that no supported cipher is available combined with 'msc' log on 'debug'.

submitting the ttcn3 test is on the way...

Actions #9

Updated by neels about 6 years ago

  • Status changed from New to In Progress
  • % Done changed from 10 to 90

I found the bug, and it's a hard to spot one. Quiz question, what's wrong in this function:

/* 4.1.2.1 after Authentication successful (or no auth rqd) */
static void vlr_loc_upd_post_auth(struct osmo_fsm_inst *fi)
{
        struct lu_fsm_priv *lfp = fi->priv;
        struct vlr_subscr *vsub = lfp->vsub;

        LOGPFSM(fi, "%s()\n", __func__);

        OSMO_ASSERT(vsub);

        if (!is_ciph_required(lfp)) {
                vlr_loc_upd_post_ciph(fi);
                return;
        }

        if (!vsub->last_tuple) {
                LOGPFSML(fi, LOGL_ERROR, "No auth tuple available\n");
                vlr_lu_compl_fsm_failure(fi, GSM48_REJECT_NETWORK_FAILURE);
                return;
        }

        if (vlr_set_ciph_mode(vsub->vlr, fi, lfp->msc_conn_ref,
                              lfp->ciphering_required,
                              vlr_use_umts_aka(&vsub->last_tuple->vec, lfp->is_r99),
                              vsub->vlr->cfg.retrieve_imeisv_ciphered)) {
                LOGPFSML(fi, LOGL_ERROR,
                         "Failed to send Ciphering Mode Command\n");
                vlr_lu_compl_fsm_failure(fi, GSM48_REJECT_NETWORK_FAILURE);
                return;
        }

        osmo_fsm_inst_state_chg(fi, VLR_ULA_S_WAIT_CIPH, LU_TIMEOUT_LONG, 0);
}

Submitting the patch now... Spoiler alert!

I must admit, to go and analyze the stack frame, I did go back to msc_vlr_tests to reproduce the issue and be able to trigger the bug without waiting for the ttcn3 suite to get going every time. So we now have a ttcn3 test (MSC_Tests.TC_lu_imsi_auth_tmsi_encr_3_1_log_msc_debug in https://gerrit.osmocom.org/7050) and an msc_vlr_test (msc_vlr_test_gsm_ciph:test_a5_3_not_supported(), patch submission pending) against this failure.

Actions #11

Updated by neels almost 6 years ago

  • Status changed from In Progress to Resolved
  • % Done changed from 90 to 100

it's about time this issue got resolved. merged a month ago.

Actions #12

Updated by neels almost 6 years ago

  • Related to Bug #3043: A5/3 encryption fails added
Actions #13

Updated by neels almost 6 years ago

upon fixing the segfault, I forgot to track the part of sending a Classmark Request. Will do so now in #3043.

Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)