diff options
Diffstat (limited to 'tests/msc_vlr/msc_vlr_test_umts_authen.err')
-rw-r--r-- | tests/msc_vlr/msc_vlr_test_umts_authen.err | 328 |
1 files changed, 164 insertions, 164 deletions
diff --git a/tests/msc_vlr/msc_vlr_test_umts_authen.err b/tests/msc_vlr/msc_vlr_test_umts_authen.err index fcaaa97da..5b3097481 100644 --- a/tests/msc_vlr/msc_vlr_test_umts_authen.err +++ b/tests/msc_vlr/msc_vlr_test_umts_authen.err @@ -21,15 +21,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -40,7 +40,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -59,7 +59,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on GERAN received SRES/RES: e229c19e791f2e41 (8 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH established UMTS security context DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -68,13 +68,13 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph() DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Allocated DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START DVLR GSUP tx: 04010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000000156f0 -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -97,28 +97,28 @@ DVLR GSUP rx 11: 06010809710000000156f0 DREF VLR subscr MSISDN:42342 usage increases to: 2 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Freeing instance DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Allocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Allocated DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START -DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE +DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: State change to SUB_PRES_VLR_S_DONE (no timeout) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout) - sending LU Accept for MSISDN:42342, with TMSI 0x03020100 DREF VLR subscr MSISDN:42342 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 @@ -150,17 +150,17 @@ DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK DREF VLR subscr MSISDN:42342 usage increases to: 2 -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Deallocated -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -170,7 +170,7 @@ DREF MSISDN:42342: MSC conn use - dtap == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -199,11 +199,11 @@ DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: DREF VLR subscr MSISDN:42342 usage increases to: 2 DREF VLR subscr MSISDN:42342 usage increases to: 3 DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi() -DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH +DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START -DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for MSISDN:42342: tuple use_count=1 key_seq=1 auth_types=0x3 and... - ...rand=c187a53a5e6b9d573cac7c74451fd46d @@ -211,7 +211,7 @@ DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: got - ...expecting res=7db47cf7f81e4dc7 DREF VLR subscr MSISDN:42342 usage decreases to: 2 DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -237,7 +237,7 @@ DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: Rec DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: 7db47cf7f81e4dc7 (8 bytes) DVLR SUBSCR(MSISDN:42342) AUTH established UMTS security context DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -250,12 +250,12 @@ DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AU DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace() DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei() DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED) -DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_DONE +DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Process Access Request result: PASSED - sending CM Service Accept for MSISDN:42342 DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED DREF MSISDN:42342: MSC conn use + cm_service == 2 (0xa: dtap,cm_service) -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: still awaiting first request after a CM Service Request DREF MSISDN:42342: MSC conn use - dtap == 1 (0x8: cm_service) cm_service_result_sent == 1 @@ -273,7 +273,7 @@ DREF MSISDN:42342: MSC conn use + trans_nc_ss == 3 (0x4a: dtap,cm_service,trans_ DMM MSISDN:42342: rx msg GSM0480_MTYPE_REGISTER: received_cm_service_request changes to false DREF MSISDN:42342: MSC conn use - cm_service == 2 (0x42: dtap,trans_nc_ss) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_COMMUNICATING (no timeout) DMM USSD: Own number requested DMM MSISDN:42342: MSISDN = 42342 DMSC msc_tx 43 bytes to MSISDN:42342 via RAN_GERAN_A @@ -283,7 +283,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 DREF MSISDN:42342: MSC conn use - trans_nc_ss == 1 (0x2: dtap) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -292,7 +292,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 - BSS sends BSSMAP Clear Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000010650) @@ -336,11 +336,11 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Rec DREF VLR subscr MSISDN:42342 usage increases to: 4 DREF VLR subscr MSISDN:42342 usage increases to: 5 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi() -DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH +DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(PAGING_RESP:901700000010650) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START -DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x3 and... - ...rand=efa9c29a9742148d5c9070348716e1bb @@ -348,7 +348,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au - ...expecting res=706f996719ba609c DREF VLR subscr MSISDN:42342 usage decreases to: 4 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -373,7 +373,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: Receiv DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: 706f996719ba609c (8 bytes) DVLR SUBSCR(MSISDN:42342) AUTH established UMTS security context DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(PAGING_RESP:901700000010650) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -386,7 +386,7 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH} DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace() DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei() DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED) -DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_DONE +DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Process Access Request result: PASSED DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED DPAG Paging success for MSISDN:42342 (event=0) @@ -398,7 +398,7 @@ DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 - DTAP matches expected message DREF VLR subscr MSISDN:42342 usage decreases to: 4 -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: connection still has active transaction: SMS DREF MSISDN:42342: MSC conn use - dtap == 1 (0x20: trans_sms) dtap_tx_confirmed == 1 @@ -414,7 +414,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 4 DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms) DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_COMMUNICATING (no timeout) DREF MSISDN:42342: MSC conn use - dtap == 1 (0x20: trans_sms) llist_count(&net->subscr_conns) == 1 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that @@ -430,7 +430,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 DREF MSISDN:42342: MSC conn use - trans_sms == 1 (0x2: dtap) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -440,7 +440,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 - BSS sends BSSMAP Clear Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(PAGING_RESP:901700000010650) @@ -468,7 +468,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 1 DREF VLR subscr MSISDN:42342 usage decreases to: 0 DREF freeing VLR subscr MSISDN:42342 DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release) - BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release) @@ -476,7 +476,7 @@ DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF unknown: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DRLL Freeing subscriber connection with NULL subscriber DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -507,15 +507,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -526,7 +526,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -545,7 +545,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on UTRAN received RES: e229c19e791f2e41 (8 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH established UMTS security context DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -556,7 +556,7 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode DMM -> SECURITY MODE CONTROL IMSI:901700000010650 - sending SecurityModeControl for UE ctx 42 send_ck=0 new_key=1 - ...ik=27497388b6cb044648f396aa155b95ef -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_CIPH (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -569,13 +569,13 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph( DIUCS IMSI:901700000010650: tx CommonID 901700000010650 - Iu Common ID --RAN_UTRAN_IU--> MS (IMSI=901700000010650) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Allocated DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START DVLR GSUP tx: 04010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000000156f0 -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s) gsup_tx_confirmed == 1 lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -595,28 +595,28 @@ DVLR GSUP rx 11: 06010809710000000156f0 DREF VLR subscr MSISDN:42342 usage increases to: 2 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Freeing instance DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Allocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Allocated DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START -DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE +DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: State change to SUB_PRES_VLR_S_DONE (no timeout) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout) - sending LU Accept for MSISDN:42342, with TMSI 0x03020100 DREF VLR subscr MSISDN:42342 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 @@ -648,17 +648,17 @@ DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK DREF VLR subscr MSISDN:42342 usage increases to: 2 -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Deallocated -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -668,7 +668,7 @@ DREF MSISDN:42342: MSC conn use - dtap == 1 (0x100: release) - RNC sends Iu Release Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -697,11 +697,11 @@ DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: DREF VLR subscr MSISDN:42342 usage increases to: 2 DREF VLR subscr MSISDN:42342 usage increases to: 3 DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi() -DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH +DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START -DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for MSISDN:42342: tuple use_count=1 key_seq=1 auth_types=0x3 and... - ...rand=c187a53a5e6b9d573cac7c74451fd46d @@ -709,7 +709,7 @@ DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: got - ...expecting res=7db47cf7f81e4dc7 DREF VLR subscr MSISDN:42342 usage decreases to: 2 DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -735,7 +735,7 @@ DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: Rec DVLR SUBSCR(MSISDN:42342) AUTH on UTRAN received RES: 7db47cf7f81e4dc7 (8 bytes) DVLR SUBSCR(MSISDN:42342) AUTH established UMTS security context DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650) DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -746,7 +746,7 @@ DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AU DMM -> SECURITY MODE CONTROL MSISDN:42342 - sending SecurityModeControl for UE ctx 42 send_ck=0 new_key=1 - ...ik=1159ec926a50e98c034a6b7d7c9f418d -DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH +DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_WAIT_CIPH (no timeout) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -763,11 +763,11 @@ DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CI DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace() DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei() DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED) -DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE +DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_WAIT_CIPH}: State change to PR_ARQ_S_DONE (no timeout) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Process Access Request result: PASSED DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED DREF MSISDN:42342: MSC conn use + cm_service == 1 (0x8: cm_service) -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: still awaiting first request after a CM Service Request cm_service_result_sent == 0 - a USSD request is serviced @@ -784,7 +784,7 @@ DREF MSISDN:42342: MSC conn use + trans_nc_ss == 3 (0x4a: dtap,cm_service,trans_ DMM MSISDN:42342: rx msg GSM0480_MTYPE_REGISTER: received_cm_service_request changes to false DREF MSISDN:42342: MSC conn use - cm_service == 2 (0x42: dtap,trans_nc_ss) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_COMMUNICATING (no timeout) DMM USSD: Own number requested DMM MSISDN:42342: MSISDN = 42342 DMSC msc_tx 43 bytes to MSISDN:42342 via RAN_UTRAN_IU @@ -794,7 +794,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 DREF MSISDN:42342: MSC conn use - trans_nc_ss == 1 (0x2: dtap) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -803,7 +803,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 - RNC sends Iu Release Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000010650) @@ -847,11 +847,11 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Rec DREF VLR subscr MSISDN:42342 usage increases to: 4 DREF VLR subscr MSISDN:42342 usage increases to: 5 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi() -DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH +DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(PAGING_RESP:901700000010650) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START -DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x3 and... - ...rand=efa9c29a9742148d5c9070348716e1bb @@ -859,7 +859,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au - ...expecting res=706f996719ba609c DREF VLR subscr MSISDN:42342 usage decreases to: 4 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -884,7 +884,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: Receiv DVLR SUBSCR(MSISDN:42342) AUTH on UTRAN received RES: 706f996719ba609c (8 bytes) DVLR SUBSCR(MSISDN:42342) AUTH established UMTS security context DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(PAGING_RESP:901700000010650) DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -895,7 +895,7 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH} DMM -> SECURITY MODE CONTROL MSISDN:42342 - sending SecurityModeControl for UE ctx 42 send_ck=0 new_key=1 - ...ik=eb50e770ddcc3060101d2f43b6c2b884 -DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH +DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_WAIT_CIPH (no timeout) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -912,7 +912,7 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH} DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace() DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei() DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED) -DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE +DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_WAIT_CIPH}: State change to PR_ARQ_S_DONE (no timeout) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Process Access Request result: PASSED DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED DPAG Paging success for MSISDN:42342 (event=0) @@ -924,7 +924,7 @@ DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_UTRAN_IU - DTAP --RAN_UTRAN_IU--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 - DTAP matches expected message DREF VLR subscr MSISDN:42342 usage decreases to: 4 -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: connection still has active transaction: SMS paging_stopped == 1 - SMS was delivered, no requests pending for subscr @@ -938,7 +938,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 4 DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms) DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_COMMUNICATING (no timeout) DREF MSISDN:42342: MSC conn use - dtap == 1 (0x20: trans_sms) llist_count(&net->subscr_conns) == 1 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that @@ -954,7 +954,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 DREF MSISDN:42342: MSC conn use - trans_sms == 1 (0x2: dtap) DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_COMMUNICATING}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -964,7 +964,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 2 - RNC sends Iu Release Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(PAGING_RESP:901700000010650) @@ -992,7 +992,7 @@ DREF VLR subscr MSISDN:42342 usage decreases to: 1 DREF VLR subscr MSISDN:42342 usage decreases to: 0 DREF freeing VLR subscr MSISDN:42342 DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release) - Iu Release --RAN_UTRAN_IU--> MS DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release) @@ -1000,7 +1000,7 @@ DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release) - RNC sends Iu Release Complete DREF unknown: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DRLL Freeing subscriber connection with NULL subscriber DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1031,15 +1031,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1050,7 +1050,7 @@ DVLR GSUP rx 111: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 1 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1068,7 +1068,7 @@ DMM IMSI:901700000010650: MM R99 AUTHENTICATION SYNCH (AUTS = 979498b1f72d3e28c5 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_FAIL DVLR GSUP tx: 08010809710000000156f0260e979498b1f72d3e28c59fa2e72f9c201039fa2f4e3d523d8619a73b4f65c3e14d GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0260e979498b1f72d3e28c59fa2e72f9c201039fa2f4e3d523d8619a73b4f65c3e14d -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1081,7 +1081,7 @@ DVLR GSUP rx 211: 0a010809710000000156f0036220100f1feb1623e1bf626334e37ec448ac18 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 2 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: state_chg to VLR_SUB_AS_WAIT_RESP_RESYNC +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: State change to VLR_SUB_AS_WAIT_RESP_RESYNC (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=0f1feb1623e1bf626334e37ec448ac18 @@ -1100,7 +1100,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: Received DVLR SUBSCR(IMSI:901700000010650) AUTH on GERAN received SRES/RES: 1df5f0b4f22b696e (8 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH established UMTS security context DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -1109,13 +1109,13 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph() DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Allocated DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START DVLR GSUP tx: 04010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000000156f0 -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1138,28 +1138,28 @@ DVLR GSUP rx 11: 06010809710000000156f0 DREF VLR subscr MSISDN:42342 usage increases to: 2 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Freeing instance DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Allocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Allocated DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START -DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE +DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: State change to SUB_PRES_VLR_S_DONE (no timeout) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout) - sending LU Accept for MSISDN:42342, with TMSI 0x03020100 DREF VLR subscr MSISDN:42342 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 @@ -1191,17 +1191,17 @@ DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK DREF VLR subscr MSISDN:42342 usage increases to: 2 -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Deallocated -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -1211,7 +1211,7 @@ DREF MSISDN:42342: MSC conn use - dtap == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1250,15 +1250,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1269,7 +1269,7 @@ DVLR GSUP rx 111: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 1 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1287,7 +1287,7 @@ DMM IMSI:901700000010650: MM R99 AUTHENTICATION SYNCH (AUTS = 979498b1f72d3e28c5 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_FAIL DVLR GSUP tx: 08010809710000000156f0260e979498b1f72d3e28c59fa2e72f9c201039fa2f4e3d523d8619a73b4f65c3e14d GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0260e979498b1f72d3e28c59fa2e72f9c201039fa2f4e3d523d8619a73b4f65c3e14d -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1300,7 +1300,7 @@ DVLR GSUP rx 211: 0a010809710000000156f0036220100f1feb1623e1bf626334e37ec448ac18 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 2 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: state_chg to VLR_SUB_AS_WAIT_RESP_RESYNC +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_SAI_RESYNC}: State change to VLR_SUB_AS_WAIT_RESP_RESYNC (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=0f1feb1623e1bf626334e37ec448ac18 @@ -1319,7 +1319,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: Received DVLR SUBSCR(IMSI:901700000010650) AUTH on UTRAN received RES: 1df5f0b4f22b696e (8 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH established UMTS security context DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: Authentication terminating with result PASSED -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: state_chg to VLR_SUB_AS_AUTHENTICATED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP_RESYNC}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTHENTICATED}: Freeing instance @@ -1330,7 +1330,7 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode DMM -> SECURITY MODE CONTROL IMSI:901700000010650 - sending SecurityModeControl for UE ctx 42 send_ck=0 new_key=1 - ...ik=8a90c769b7272f3bb7a1c1fbb1ea9349 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_CIPH (T0, 30s) DREF IMSI:901700000010650: MSC conn use - dtap == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1343,13 +1343,13 @@ DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph( DIUCS IMSI:901700000010650: tx CommonID 901700000010650 - Iu Common ID --RAN_UTRAN_IU--> MS (IMSI=901700000010650) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_CIPH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Allocated DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START DVLR GSUP tx: 04010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000000156f0 -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s) gsup_tx_confirmed == 1 lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1369,28 +1369,28 @@ DVLR GSUP rx 11: 06010809710000000156f0 DREF VLR subscr MSISDN:42342 usage increases to: 2 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK -DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE +DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Freeing instance DVLR upd_hlr_vlr_fsm(LU:901700000010650){UPD_HLR_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Allocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Allocated DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START -DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE +DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_INIT}: State change to SUB_PRES_VLR_S_DONE (no timeout) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000010650) DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(LU:901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout) - sending LU Accept for MSISDN:42342, with TMSI 0x03020100 DREF VLR subscr MSISDN:42342 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 @@ -1422,17 +1422,17 @@ DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK DREF VLR subscr MSISDN:42342 usage increases to: 2 -DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000010650) DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(LU:901700000010650){LU_COMPL_VLR_S_DONE}: Deallocated -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_ACCEPTED (T0, 5s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_ACCEPTED}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF MSISDN:42342: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr MSISDN:42342 usage increases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -1442,7 +1442,7 @@ DREF MSISDN:42342: MSC conn use - dtap == 1 (0x100: release) - RNC sends Iu Release Complete DREF MSISDN:42342: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1481,15 +1481,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1500,7 +1500,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1519,7 +1519,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on GERAN received SRES/RES: e229c19e791f2e (7 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH SRES/RES has invalid length: 7. Expected either 4 (GSM AKA) or 8 (UMTS AKA) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -1528,9 +1528,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -1541,7 +1541,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1579,15 +1579,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1598,7 +1598,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1617,7 +1617,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on UTRAN received RES: e229c19e791f2e (7 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH RES has invalid length: 7. Expected 8 (UMTS AKA) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -1626,9 +1626,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -1639,7 +1639,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - RNC sends Iu Release Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1677,15 +1677,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1696,7 +1696,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1715,7 +1715,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on GERAN received SRES/RES: e229c19e791f2e4123 (9 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH SRES/RES has invalid length: 9. Expected either 4 (GSM AKA) or 8 (UMTS AKA) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -1724,9 +1724,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -1737,7 +1737,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1775,15 +1775,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1794,7 +1794,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1813,7 +1813,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on UTRAN received RES: e229c19e791f2e4123 (9 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH RES has invalid length: 9. Expected 8 (UMTS AKA) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -1822,9 +1822,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -1835,7 +1835,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - RNC sends Iu Release Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1873,15 +1873,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1892,7 +1892,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -1911,7 +1911,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on GERAN received SRES/RES: e229c19e (4 bytes) DVLR SUBSCR(IMSI:901700000010650) GSM AUTH failure: mismatching sres (expected sres=9b 36 ef df ) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -1920,9 +1920,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -1933,7 +1933,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - BSS sends BSSMAP Clear Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) @@ -1971,15 +1971,15 @@ DVLR New subscr, IMSI: 901700000010650 DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: vlr_loc_upd_node1() -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000010650) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START DVLR GSUP tx: 08010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0 -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_NEW}: State change to SUBSCR_CONN_S_AUTH_CIPH (T0, 5s) DREF IMSI:901700000010650: MSC conn use - compl_l3 == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED @@ -1990,7 +1990,7 @@ DVLR GSUP rx 511: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK DVLR SUBSCR(IMSI:901700000010650) Received 5 auth tuples -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use UMTS AKA (is_r99=yes, at->vec.auth_types=0x3) - sending UMTS Auth Request for IMSI:901700000010650: tuple use_count=1 key_seq=0 auth_types=0x3 and... - ...rand=39fa2f4e3d523d8619a73b4f65c3e14d @@ -2009,7 +2009,7 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Received Event DVLR SUBSCR(IMSI:901700000010650) AUTH on UTRAN received RES: e229c19e (4 bytes) DVLR SUBSCR(IMSI:901700000010650) AUTH via UTRAN, cannot allow GSM AKA (MS is R99 capable, vec has UMTS AKA tokens, res_len=4 is INVALID on UTRAN) DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result Illegal MS -DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTH_FAILED +DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTH_FAILED (no timeout) DVLR GSUP tx: 0b010809710000000156f0 GSUP --> HLR: OSMO_GSUP_MSGT_AUTH_FAIL_REPORT: 0b010809710000000156f0 DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) @@ -2018,9 +2018,9 @@ DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Freeing insta DVLR VLR_Authenticate(LU:901700000010650){VLR_SUB_AS_AUTH_FAILED}: Deallocated DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES - sending LU Reject for IMSI:901700000010650, cause 3 -DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE +DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_DONE (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: State change to SUBSCR_CONN_S_RELEASING (T0, 5s) DREF IMSI:901700000010650: MSC conn use + release == 2 (0x102: dtap,release) DREF VLR subscr IMSI:901700000010650 usage increases to: 2 DREF VLR subscr IMSI:901700000010650 usage decreases to: 1 @@ -2031,7 +2031,7 @@ DREF IMSI:901700000010650: MSC conn use - dtap == 1 (0x100: release) - RNC sends Iu Release Complete DREF IMSI:901700000010650: MSC conn use - release == 0 (0x0: ) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED -DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASING}: State change to SUBSCR_CONN_S_RELEASED (no timeout) DMM Subscr_Conn(LU:901700000010650){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(LU:901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000010650) |