diff options
Diffstat (limited to 'tests/msc_vlr/msc_vlr_test_ms_timeout.err')
| -rw-r--r-- | tests/msc_vlr/msc_vlr_test_ms_timeout.err | 157 |
1 files changed, 92 insertions, 65 deletions
diff --git a/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/tests/msc_vlr/msc_vlr_test_ms_timeout.err index fc4e4896e..a3950edc2 100644 --- a/tests/msc_vlr/msc_vlr_test_ms_timeout.err +++ b/tests/msc_vlr/msc_vlr_test_ms_timeout.err @@ -6,12 +6,9 @@ talloc_total_blocks(tall_bsc_ctx) == 12 - Location Update request causes a GSUP Send Auth Info request to HLR MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST new conn +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated DREF unknown: MSC conn use + compl_l3 == 1 (0x1) DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) -DREF unknown: MSC conn use + fsm == 2 (0x5) -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH DMM LU/new-LAC: 1/23 @@ -32,8 +29,11 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VL DVLR GSUP tx: 08010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0 DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI -DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW) -DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED lu_result_sent == 0 - from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800 @@ -69,13 +69,22 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 llist_count(&net->subscr_conns) == 1 lu_result_sent == 0 - Total time passed: 5.001598 s -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Timeout of T0 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Timeout of T0 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Close event, cause 38 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DREF IMSI:901700000004620: MSC conn use + release == 1 (0x100) DREF VLR subscr IMSI:901700000004620 usage increases to: 2 DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Connection timed out - sending LU Reject for IMSI:901700000004620, cause 22 DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_CN_CLOSE +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_CN_CLOSE not permitted +DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 +- BSSAP Clear --RAN_GERAN_A--> MS +DREF IMSI:901700000004620: MSC conn use - release == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -86,15 +95,11 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Co DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated -DMM msc_subscr_conn_close(vsub=IMSI:901700000004620, cause=2): no conn fsm, releasing directly without release event. -- BSSAP Clear --RAN_GERAN_A--> MS -DREF IMSI:901700000004620: MSC conn use - fsm == 0 (0x0) -DRLL subscr IMSI:901700000004620: Freeing subscriber connection -DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated +DRLL IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 DREF freeing VLR subscr IMSI:901700000004620 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated - SUBSCR_CONN_TIMEOUT has passed, conn is gone. bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -109,12 +114,9 @@ talloc_total_blocks(tall_bsc_ctx) == 12 - Location Update request causes a GSUP Send Auth Info request to HLR MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST new conn +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated DREF unknown: MSC conn use + compl_l3 == 1 (0x1) DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) -DREF unknown: MSC conn use + fsm == 2 (0x5) -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH DMM LU/new-LAC: 1/23 @@ -135,8 +137,11 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VL DVLR GSUP tx: 08010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0 DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI -DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW) -DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED lu_result_sent == 0 - from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000 @@ -155,7 +160,7 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 lu_result_sent == 0 - MS sends Authen Response, VLR accepts and sends GSUP LU Req to HLR MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP -DREF IMSI:901700000004620: MSC conn use + dtap == 2 (0x6) +DREF IMSI:901700000004620: MSC conn use + dtap == 1 (0x2) DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14) DMM IMSI:901700000004620: MM GSM AUTHENTICATION RESPONSE (sres = 2d8b2c3e) DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP @@ -178,8 +183,9 @@ DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HL DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA -DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW) -DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4) +DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -227,21 +233,24 @@ DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from paren DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DREF MSISDN:46071: MSC conn use + release == 1 (0x100) +DREF VLR subscr MSISDN:46071 usage increases to: 4 +DREF VLR subscr MSISDN:46071 usage decreases to: 3 +- BSSAP Clear --RAN_GERAN_A--> MS +DREF MSISDN:46071: MSC conn use - release == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated -DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- BSSAP Clear --RAN_GERAN_A--> MS -DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0) -DRLL subscr MSISDN:46071: Freeing subscriber connection +DRLL MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -255,13 +264,10 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 - after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ new conn +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated DREF unknown: MSC conn use + compl_l3 == 1 (0x1) DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24) DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620 -DREF unknown: MSC conn use + fsm == 2 (0x5) -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from CM_SERVICE_REQ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620) @@ -280,8 +286,11 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us - ...rand=12aca96fb4ffdea5c985cbafa9b6e18b - ...expecting sres=20bde240 DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW) -DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED cm_service_result_sent == 0 auth_request_sent == 1 --- @@ -303,15 +312,24 @@ DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4) llist_count(&net->subscr_conns) == 1 cm_service_result_sent == 0 - Total time passed: 5.001598 s -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Timeout of T0 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Timeout of T0 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Close event, cause 38 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING +DREF MSISDN:46071: MSC conn use + release == 1 (0x100) DREF VLR subscr MSISDN:46071 usage increases to: 3 DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_WAIT_AUTH}: Connection timed out DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(VLR_PR_ARQ_RES_TIMEOUT) DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_DONE DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_TIMEOUT - sending CM Service Reject for MSISDN:46071, result VLR_PR_ARQ_RES_TIMEOUT -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_CN_CLOSE +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_CN_CLOSE not permitted +DREF VLR subscr MSISDN:46071 usage decreases to: 2 +- BSSAP Clear --RAN_GERAN_A--> MS +DREF MSISDN:46071: MSC conn use - release == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -321,14 +339,10 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: Deallocated DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620) DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated -DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- BSSAP Clear --RAN_GERAN_A--> MS -DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0) -DRLL subscr MSISDN:46071: Freeing subscriber connection -DREF VLR subscr MSISDN:46071 usage decreases to: 2 +DRLL MSISDN:46071: Freeing subscriber connection +DREF VLR subscr MSISDN:46071 usage decreases to: 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated -DREF VLR subscr MSISDN:46071 usage decreases to: 1 - SUBSCR_CONN_TIMEOUT has passed, conn is gone. bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -344,12 +358,9 @@ talloc_total_blocks(tall_bsc_ctx) == 12 - Location Update request causes a GSUP LU request to HLR MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST new conn +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated DREF unknown: MSC conn use + compl_l3 == 1 (0x1) DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) -DREF unknown: MSC conn use + fsm == 2 (0x5) -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH DMM LU/new-LAC: 1/23 @@ -373,8 +384,11 @@ DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HL DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA -DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW) -DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3 +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH +DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -422,21 +436,24 @@ DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from paren DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn -DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING +DREF MSISDN:46071: MSC conn use + release == 1 (0x100) +DREF VLR subscr MSISDN:46071 usage increases to: 4 +DREF VLR subscr MSISDN:46071 usage decreases to: 3 +- BSSAP Clear --RAN_GERAN_A--> MS +DREF MSISDN:46071: MSC conn use - release == 0 (0x0) +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED +DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated -DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- BSSAP Clear --RAN_GERAN_A--> MS -DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0) -DRLL subscr MSISDN:46071: Freeing subscriber connection +DRLL MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -498,6 +515,7 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 3 - subscriber detaches, pagings are canceled MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND new conn +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated DREF unknown: MSC conn use + compl_l3 == 1 (0x1) DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1) DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620 @@ -510,10 +528,19 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 2 DREF VLR subscr MSISDN:46071 usage decreases to: 1 DREF VLR subscr MSISDN:46071 usage decreases to: 0 DREF freeing VLR subscr MSISDN:46071 -DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event. +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Close event, cause 0 +DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING +DREF unknown: MSC conn use + release == 2 (0x101) - BSSAP Clear --RAN_GERAN_A--> MS +DREF unknown: MSC conn use - release == 1 (0x1) DREF unknown: MSC conn use - compl_l3 == 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_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DRLL Freeing subscriber connection with NULL subscriber +DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance +DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated bssap_clear_sent == 1 paging_stopped == 1 llist_count(&net->subscr_conns) == 0 |