Project

General

Profile

Bug #4007

msc crashes with sigsegv on "sh subscriber msisdn xxxxx" via vty

Added by roh 5 months ago. Updated 3 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
05/17/2019
Due date:
% Done:

100%

Resolution:

Description

the msc was restarted as last componen in this cni.
afterwards a phone was rebooted into the network.

cli:

OsmoMSC# sh subscriber extension 23841
    Extension: 23841
    LAC: 1/0x1
    RAN: GERAN-A
    IMSI: 901700000023841
    TMSI: A3B562AC
    Flags: 
     IMSI detached:             false
     Conf. by radio contact:    true
     Subscr. data conf. by HLR: true
     Location conf. in HLR:     true
     Subscriber dormant:        false
     Received cancel locataion: false
     MS not reachable:          false
     LA allowed:                true
    A3A8 last tuple (used 1 times):
     seq # : 4
     RAND  : 36 ae bb 07 1b c7 54 c4 24 e2 8d 14 1c 33 1c 25 
     SRES  : e3 a2 0c 3c 
     Kc    : c5 16 cd 69 9f 51 e0 00 
    Paging: not paging for 0 requests
    SGs-state: SGs-NULL
    SGs-MME: (none)
    Use: 3 (attached,2*gsm0911_gsup_rx)
OsmoMSC# subscriber msisdn 23841 silent-call start any speech-fr 
% Silent call initiated
OsmoMSC# sh subscriber extension 23841

<segfault>

similar setup to #4003 but different backtrace:

(gdb) r
Starting program: /usr/bin/osmo-msc -c /etc/osmocom/osmo-msc.cfg
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
<001f> osmo_ss7.c:1326 0: ASP Restart for server not implemented yet!
<0013> telnet_interface.c:104 Available via telnet 127.0.0.1 4254
<000c> smpp_smsc.c:1017 SMPP at 0.0.0.0 2775
<001a> control_if.c:911 CTRL at 127.0.0.1 4255
<0009> db.c:619 Init database connection to 'sms.db' using libdbi v0.9.0
<001d> gsup_client.c:73 GSUP connecting to 127.0.0.1:4222
<0023> mgcp_client.c:716 MGCP client: using endpoint domain '@mgw'
<0013> socket.c:228 unable to bind socket: 0.0.0.0:2727: Address already in use
<0013> socket.c:237 no suitable local addr found for: 0.0.0.0:2727
<0023> mgcp_client.c:749 MGCPGW failed to bind to 0.0.0.0:2727, retrying with port 2728
<0020> sccp_user.c:515 OsmoMSC-A-Iu: Using SS7 instance 0, pc:0.23.1
<0020> sccp_user.c:533 OsmoMSC-A-Iu: Using AS instance as-clnt-OsmoMSC-A-Iu
<0020> sccp_user.c:538 OsmoMSC-A-Iu: Creating default route
<0020> sccp_user.c:594 OsmoMSC-A-Iu: Using ASP instance asp-clnt-OsmoMSC-A-Iu
<001f> osmo_ss7.c:471 0: Creating SCCP instance
<0011> sgs_server.c:186 SGs socket bound to r=NULL<->l=0.0.0.0:29118
<0006> msc_main.c:688 A-interface: SCCP user OsmoMSC-A:RI=SSN_PC,PC=(no PC),SSN=BSSAP, cs7-instance 0 ((null))
<0006> msc_main.c:707 Iu-interface: SCCP user OsmoMSC-IuCS:RI=SSN_PC,PC=(no PC),SSN=RANAP, cs7-instance 0 ((null))
<0015> input/ipa.c:128 127.0.0.1:4222 connection done
<0015> input/ipaccess.c:705 received ID get from 0/0/0
<0022> m3ua.c:634 asp-asp-clnt-OsmoMSC-A-Iu: Received NOTIFY Type State Change:AS Inactive ()
<001f> xua_default_lm_fsm.c:353 xua_default_lm(asp-clnt-OsmoMSC-A-Iu)[0x555555953900]{ACTIVE}: Ignoring primitive M-ASP_ACTIVE.confirm
<0022> m3ua.c:634 asp-asp-clnt-OsmoMSC-A-Iu: Received NOTIFY Type State Change:AS Active ()

<0010> ran_peer.c:248 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ad80]{WAIT_RX_RESET}: Receiving CO message on RAN peer that has not done a proper RESET yet. Disconnecting on incoming message, sending RESET to RAN peer.
<0020> sccp_scoc.c:1677 SCCP-SCOC(0)[0x555555956610]{DISCONN_PEND}: Event RCOC-DT1.ind not permitted
<000e> fsm.c:423 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: Allocated
<000e> fsm.c:453 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000023841:GERAN-A-1:LU)[0x555555959430]
<000e> vlr_lu_fsm.c:1525 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_lu_fsm.c:1531 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
<000e> vlr.c:435 set IMSI on subscriber; IMSI=901700000023841 id=901700000023841
<000e> vlr.c:386 New subscr, IMSI: 901700000023841
<000e> vlr_lu_fsm.c:933 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
<000e> vlr_lu_fsm.c:910 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
<000e> vlr_lu_fsm.c:917 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:318 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s)
<0005> ran_peer.c:105 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ad80]{READY}: Added seen cell to this RAN peer: CGI:901-70-1-0
<000e> vlr.c:755 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
<000e> vlr.c:735 SUBSCR(IMSI-901700000023841) Received 5 auth tuples
<000e> vlr_auth_fsm.c:374 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1328 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841) AUTH on GERAN received SRES/RES: 97e59080 (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]
<000e> vlr_auth_fsm.c:253 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
<000e> vlr_lu_fsm.c:864 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
<000e> vlr_lu_fsm.c:831 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph()
<000e> vlr_lu_fsm.c:792 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4()
<000e> vlr_lu_fsm.c:801 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s)
<000e> fsm.c:423 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_INIT}: Allocated
<000e> fsm.c:453 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x5555559565a0]
<000e> vlr_lu_fsm.c:176 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
<000e> vlr_lu_fsm.c:87 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s)
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595b940]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> vlr.c:778 IMSI:901700000023841 has MSISDN:23841
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr.c:879 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
<000e> vlr_lu_fsm.c:1220 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
<000e> vlr_lu_fsm.c:109 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x5555559565a0]
<000e> vlr_lu_fsm.c:110 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
<000e> vlr_lu_fsm.c:1228 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s)
<000e> fsm.c:423 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_INIT}: Allocated
<000e> fsm.c:453 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x5555559565a0]
<000e> vlr_lu_fsm.c:774 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
<000e> vlr_lu_fsm.c:418 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s)
<000e> vlr_lu_fsm.c:425 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
<000e> vlr_lu_fsm.c:434 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSInew-0x2F1EE9E6) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:443 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout)
<000e> fsm.c:535 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-1:LU)[0x55555595aa00]{UPD_HLR_VLR_S_DONE}: Deallocated
<000e> vlr.c:1190 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSInew-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
<000e> vlr_lu_fsm.c:1262 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:353 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:388 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
<000e> vlr_lu_fsm.c:782 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<000e> vlr_lu_fsm.c:782 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]
<000e> fsm.c:535 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-1:LU)[0x55555595ba00]{LU_COMPL_VLR_S_DONE}: Deallocated
<000e> vlr_lu_fsm.c:750 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout)
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x555555959430])
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x555555959430]
<000e> vlr_lu_fsm.c:1450 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
<000e> fsm.c:514 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x5555559565a0]{VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-1:LU)[0x555555959430]
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595dda0]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:333 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
<000e> vlr_access_req_fsm.c:340 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:322 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1328 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH on GERAN received SRES/RES: b8d39814 (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]
<000e> vlr_auth_fsm.c:253 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
<000e> vlr_access_req_fsm.c:284 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
<000e> vlr_access_req_fsm.c:250 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_ciph()
<000e> vlr_access_req_fsm.c:222 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_vlr()
<000e> vlr_access_req_fsm.c:207 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_pres()
<000e> vlr_access_req_fsm.c:191 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace()
<000e> vlr_access_req_fsm.c:169 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei()
<000e> vlr_access_req_fsm.c:182 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_DONE}: Process Access Request result: PASSED
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595e1f0]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595dda0])
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595dda0]
<000e> fsm.c:514 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595d2e0]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-2:CM_SERVICE_REQ)[0x55555595dda0]
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555958940]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:333 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
<000e> vlr_access_req_fsm.c:340 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:322 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1328 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH on GERAN received SRES/RES: 26048bda (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]
<000e> vlr_auth_fsm.c:253 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
<000e> vlr_access_req_fsm.c:284 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
<000e> vlr_access_req_fsm.c:250 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_ciph()
<000e> vlr_access_req_fsm.c:222 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_vlr()
<000e> vlr_access_req_fsm.c:207 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_pres()
<000e> vlr_access_req_fsm.c:191 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace()
<000e> vlr_access_req_fsm.c:169 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei()
<000e> vlr_access_req_fsm.c:182 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_DONE}: Process Access Request result: PASSED
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555956620]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<0010> msc_a.c:1252 msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555958940]{MSC_A_ST_COMMUNICATING}: Rx Assignment Complete, but no RTP stream is set up
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555958940])
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555958940]
<000e> fsm.c:514 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x5555559564f0]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-3:PAGING_RESP)[0x555555958940]
<0002> silent_call.c:167 IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6: Cannot stop silent call, no connection for subscriber
<0006> silent_call.c:52 NULL{fi=NULL}: Silent call: MS not responding to Paging
<0002> silent_call.c:167 IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6: Cannot stop silent call, no connection for subscriber
<0006> silent_call.c:52 NULL{fi=NULL}: Silent call: MS not responding to Paging
<0006> silent_call.c:52 NULL{fi=NULL}: Silent call: MS not responding to Paging
<0006> silent_call.c:52 NULL{fi=NULL}: Silent call: MS not responding to Paging
<0006> silent_call.c:52 NULL{fi=NULL}: Silent call: MS not responding to Paging
<000e> fsm.c:423 vlr_lu_fsm(TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: Allocated
<000e> fsm.c:453 vlr_lu_fsm(TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: is child of msc_a(TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555958760]
<000e> vlr_lu_fsm.c:1525 vlr_lu_fsm(TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_lu_fsm.c:1531 vlr_lu_fsm(TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
<000e> vlr_lu_fsm.c:933 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
<000e> vlr_lu_fsm.c:910 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
<000e> vlr_lu_fsm.c:917 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:322 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=3 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1328 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH on GERAN received SRES/RES: e34bae5d (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]
<000e> vlr_auth_fsm.c:253 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
<000e> vlr_lu_fsm.c:864 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
<000e> vlr_lu_fsm.c:831 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph()
<000e> vlr_lu_fsm.c:792 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4()
<000e> vlr_lu_fsm.c:801 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s)
<000e> fsm.c:423 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_INIT}: Allocated
<000e> fsm.c:453 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]
<000e> vlr_lu_fsm.c:176 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
<000e> vlr_lu_fsm.c:87 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s)
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595cb70]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> vlr.c:778 IMSI:901700000023841 has MSISDN:23841
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr.c:879 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
<000e> vlr_lu_fsm.c:1220 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
<000e> vlr_lu_fsm.c:109 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]
<000e> vlr_lu_fsm.c:110 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
<000e> vlr_lu_fsm.c:1228 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s)
<000e> fsm.c:423 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_INIT}: Allocated
<000e> fsm.c:453 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x555555956300]
<000e> vlr_lu_fsm.c:774 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
<000e> vlr_lu_fsm.c:418 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s)
<000e> vlr_lu_fsm.c:425 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
<000e> vlr_lu_fsm.c:434 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:TMSInew-0xA3B562AC) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:443 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout)
<000e> fsm.c:535 upd_hlr_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a8e0]{UPD_HLR_VLR_S_DONE}: Deallocated
<000e> vlr.c:1190 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:TMSInew-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
<000e> vlr_lu_fsm.c:1262 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:353 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:388 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
<000e> vlr_lu_fsm.c:782 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<000e> vlr_lu_fsm.c:782 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]
<000e> fsm.c:535 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x2F1EE9E6:GERAN-A-4:LU)[0x55555595a3a0]{LU_COMPL_VLR_S_DONE}: Deallocated
<000e> vlr_lu_fsm.c:750 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout)
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555958760])
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555958760]
<000e> vlr_lu_fsm.c:1450 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
<000e> fsm.c:514 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555956300]{VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-4:LU)[0x555555958760]
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595cc70]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:333 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
<000e> vlr_access_req_fsm.c:340 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:322 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=4 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1328 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC) AUTH on GERAN received SRES/RES: e3a20c3c (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]
<000e> vlr_auth_fsm.c:253 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
<000e> vlr_access_req_fsm.c:284 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
<000e> vlr_access_req_fsm.c:250 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_ciph()
<000e> vlr_access_req_fsm.c:222 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_vlr()
<000e> vlr_access_req_fsm.c:207 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_pres()
<000e> vlr_access_req_fsm.c:191 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace()
<000e> vlr_access_req_fsm.c:169 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei()
<000e> vlr_access_req_fsm.c:182 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_DONE}: Process Access Request result: PASSED
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595d5e0]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595cc70])
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595cc70]
<000e> fsm.c:514 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x555555955f60]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0xA3B562AC:GERAN-A-5:CM_SERVICE_REQ)[0x55555595cc70]

Program received signal SIGSEGV, Segmentation fault.
vty_dump_one_trans (vty=vty@entry=0x555555951460, trans=trans@entry=0x55555595a570) at msc_vty.c:720
720    msc_vty.c: No such file or directory.
(gdb) 
(gdb) 
(gdb) 
(gdb) bt
#0  vty_dump_one_trans (vty=vty@entry=0x555555951460, trans=trans@entry=0x55555595a570) at msc_vty.c:720
#1  0x00005555555682ab in subscr_dump_full_vty (vty=vty@entry=0x555555951460, vsub=vsub@entry=0x555555959560) at msc_vty.c:833
#2  0x000055555556a3a2 in show_subscr (self=<optimized out>, vty=0x555555951460, argc=<optimized out>, argv=<optimized out>) at msc_vty.c:982
#3  0x00007ffff7bbf7c1 in cmd_execute_command_real (vline=vline@entry=0x5555559592e0, vty=vty@entry=0x555555951460, cmd=0x0) at command.c:2320
#4  0x00007ffff7bc2231 in cmd_execute_command (vline=vline@entry=0x5555559592e0, vty=vty@entry=0x555555951460, cmd=cmd@entry=0x0, vtysh=vtysh@entry=0) at command.c:2353
#5  0x00007ffff7bc4740 in vty_command (buf=<optimized out>, vty=0x555555951460) at vty.c:431
#6  vty_execute (vty=0x555555951460) at vty.c:695
#7  vty_read (vty=<optimized out>) at vty.c:1419
#8  0x00007ffff7bc6831 in client_data (fd=0x555555952378, what=1) at telnet_interface.c:147
#9  0x00007ffff7525667 in osmo_fd_disp_fds (_eset=0x7fffffffea40, _wset=0x7fffffffe9c0, _rset=0x7fffffffe940) at select.c:223
#10 osmo_select_main (polling=0) at select.c:263
#11 0x0000555555564be5 in main (argc=3, argv=<optimized out>) at msc_main.c:723
(gdb) 

History

#1 Updated by laforge 5 months ago

  • Assignee set to neels

#2 Updated by neels 4 months ago

  • Status changed from New to Feedback
  • Assignee changed from neels to roh

roh can you test again with current master? Code has changed since you reported the bug. Looking at the current code, I don't see any possible NULL dereferences. (I'm not entirely sure how to reproduce, so would prefer if you do that)

#3 Updated by roh 4 months ago

i just tried to reproduce the issue and could not make it.

the 'trick' was to restart the msc last.

then ask the msc for "sh subscriber extension 23841" (which fails since the mobile thinks it still registered, the msc doesnt know of it)
usually repeating this on the vty before and after starting a silent call triggered the bug.

#4 Updated by roh 3 months ago

  • Status changed from Feedback to Resolved
  • % Done changed from 0 to 100

retested against OsmoMSC 1.3.1.175-1c500 (OsmoMSC). and i could not reproduce/force this anymore. i guess this bug got squashed already.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)