diff options
Diffstat (limited to 'openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err')
-rw-r--r-- | openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err | 105 |
1 files changed, 31 insertions, 74 deletions
diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err index 4e1c57d9a..830c83197 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err @@ -28,8 +28,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - Another Location Update Request from the same subscriber on another connection is rejected @@ -51,6 +49,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: A Location Updating process is DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR 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) @@ -58,14 +57,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 unknown leaving bsc_subscr_con_free() to bsc_api.c, owned_by_msc = false +DRLL Freeing subscriber connection with NULL subscriber DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DRR 901700000004620: internal error during Location Updating attempt -DMM No conn_fsm, release conn -DMM compl_l3: Discarding conn -DRLL Freeing subscriber connection with NULL subscriber lu_result_sent == 2 llist_count(&net->subscr_conns) == 1 --- @@ -126,7 +122,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -172,8 +167,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 --- @@ -241,7 +234,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -287,8 +279,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 --- @@ -358,7 +348,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -404,8 +393,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 --- @@ -474,7 +461,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -522,8 +508,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -582,7 +566,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -624,8 +607,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true cm_service_result_sent == 1 msc_subscr_conn_is_accepted() == true - An erratic LU request on the same conn results in conn termination @@ -640,7 +621,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -685,8 +665,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -745,7 +723,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -787,8 +764,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true cm_service_result_sent == 1 msc_subscr_conn_is_accepted() == true - Another CM Service Request request on the same conn results in conn termination @@ -804,7 +779,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -849,8 +823,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -909,7 +881,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -951,8 +922,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true cm_service_result_sent == 1 msc_subscr_conn_is_accepted() == true --- @@ -975,7 +944,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING DMM USSD: Own number requested DMM MSISDN:46071: MSISDN = 46071 -- DTAP --> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d +DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d - DTAP matches expected message DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_BUMP DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED @@ -984,7 +954,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1029,8 +998,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1089,7 +1056,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1104,10 +1070,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 DREF VLR subscr MSISDN:46071 usage increases to: 2 llist_count(&vsub->cs.requests) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 3 -DMM Subscriber MSISDN:46071 not paged yet. - BTS/BSC sends out paging request to IMSI:901700000004620 for channel type 1 - strcmp(paging_expecting_imsi, sub->imsi) == 0 -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DMM Subscriber MSISDN:46071 not paged yet, start paging. + RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 0 + strcmp(paging_expecting_imsi, imsi) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 4 llist_count(&vsub->cs.requests) == 1 DREF VLR subscr MSISDN:46071 usage decreases to: 3 @@ -1140,16 +1105,16 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DPAG Paging success for MSISDN:46071 (event=0) +DPAG Calling paging cbfn. DREF VLR subscr MSISDN:46071 usage increases to: 6 DMSC subscr MSISDN:46071: increased subscr_con use_count to 1 -- DTAP --> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 +DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1173,7 +1138,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event S rx from MS: pdisc=0x89 msg_type=0x01 DRLL Dispatching 04.08 message, pdisc=9 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING -- DTAP --> MS: 0904 +DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 0904 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 3 DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1185,7 +1151,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1231,8 +1196,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1291,7 +1254,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1306,10 +1268,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 DREF VLR subscr MSISDN:46071 usage increases to: 2 llist_count(&vsub->cs.requests) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 3 -DMM Subscriber MSISDN:46071 not paged yet. - BTS/BSC sends out paging request to IMSI:901700000004620 for channel type 1 - strcmp(paging_expecting_imsi, sub->imsi) == 0 -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DMM Subscriber MSISDN:46071 not paged yet, start paging. + RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 0 + strcmp(paging_expecting_imsi, imsi) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 4 llist_count(&vsub->cs.requests) == 1 DREF VLR subscr MSISDN:46071 usage decreases to: 3 @@ -1342,16 +1303,16 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DPAG Paging success for MSISDN:46071 (event=0) +DPAG Calling paging cbfn. DREF VLR subscr MSISDN:46071 usage increases to: 6 DMSC subscr MSISDN:46071: increased subscr_con use_count to 1 -- DTAP --> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 +DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1376,7 +1337,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event S rx from MS: pdisc=0x89 msg_type=0x01 DRLL Dispatching 04.08 message, pdisc=9 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING -- DTAP --> MS: 0904 +DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 0904 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 3 DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1388,7 +1350,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1434,8 +1395,6 @@ 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 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM IMSI:901700000004620 owned_by_msc = true lu_result_sent == 0 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1494,7 +1453,6 @@ 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1509,10 +1467,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 DREF VLR subscr MSISDN:46071 usage increases to: 2 llist_count(&vsub->cs.requests) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 3 -DMM Subscriber MSISDN:46071 not paged yet. - BTS/BSC sends out paging request to IMSI:901700000004620 for channel type 1 - strcmp(paging_expecting_imsi, sub->imsi) == 0 -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DMM Subscriber MSISDN:46071 not paged yet, start paging. + RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 0 + strcmp(paging_expecting_imsi, imsi) == 0 DREF VLR subscr MSISDN:46071 usage increases to: 4 llist_count(&vsub->cs.requests) == 1 DREF VLR subscr MSISDN:46071 usage decreases to: 3 @@ -1545,16 +1502,16 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED -DREF BSC subscr IMSI:901700000004620 usage decreases to: 0 +DPAG Paging success for MSISDN:46071 (event=0) +DPAG Calling paging cbfn. DREF VLR subscr MSISDN:46071 usage increases to: 6 DMSC subscr MSISDN:46071: increased subscr_con use_count to 1 -- DTAP --> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 +DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1577,7 +1534,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event S rx from MS: pdisc=0x89 msg_type=0x01 DRLL Dispatching 04.08 message, pdisc=9 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING -- DTAP --> MS: 0904 +DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 0904 - DTAP matches expected message DREF VLR subscr MSISDN:46071 usage decreases to: 3 DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1589,7 +1547,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca 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 MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance |