From c4914d9c4f6a3271f382453ae0abd30741ca5327 Mon Sep 17 00:00:00 2001 From: Neels Hofmeyr Date: Thu, 9 Mar 2017 16:53:25 +0100 Subject: vlr tests: umts auth with tmsi Change-Id: I136fa85b234dfeb0e8017d8c3401f7f42114b6ff --- openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c | 43 +++++- openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err | 168 +++++++++++++++++---- 2 files changed, 179 insertions(+), 32 deletions(-) diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c index 219be3ab7..999c1d2bc 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c @@ -29,6 +29,7 @@ void _test_umts_authen(enum ran_type via_ran) const char *imsi = "901700000010650"; net->authentication_required = true; + net->vlr->cfg.assign_tmsi = true; rx_from_ran = via_ran; btw("Location Update request causes a GSUP Send Auth Info request to HLR"); @@ -112,8 +113,25 @@ void _test_umts_authen(enum ran_type via_ran) btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); gsup_rx("06010809710000000156f0", NULL); - btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); + + btw("a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl"); + EXPECT_CONN_COUNT(1); + EXPECT_ACCEPTED(false); + thwart_rx_non_initial_requests(); + + btw("even though the TMSI is not acked, we can already find the subscr with it"); + vsub = vlr_subscr_find_by_tmsi(net->vlr, 0x03020100); + VERBOSE_ASSERT(vsub != NULL, == true, "%d"); + VERBOSE_ASSERT(strcmp(vsub->imsi, imsi), == 0, "%d"); + VERBOSE_ASSERT(vsub->tmsi_new, == 0x03020100, "0x%08x"); + VERBOSE_ASSERT(vsub->tmsi, == GSM_RESERVED_TMSI, "0x%08x"); + vlr_subscr_put(vsub); + + btw("MS sends TMSI Realloc Complete"); + ms_sends_msg("055b"); + + btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); BTW("after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector"); @@ -264,7 +282,11 @@ extern int milenage_f1(const u8 *opc, const u8 *k, const u8 *_rand, void _test_umts_authen_resync(enum ran_type via_ran) { + struct vlr_subscr *vsub; + const char *imsi = "901700000010650"; + net->authentication_required = true; + net->vlr->cfg.assign_tmsi = true; rx_from_ran = via_ran; btw("Location Update request causes a GSUP Send Auth Info request to HLR"); @@ -428,8 +450,25 @@ void _test_umts_authen_resync(enum ran_type via_ran) btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); gsup_rx("06010809710000000156f0", NULL); - btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); + + btw("a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl"); + EXPECT_CONN_COUNT(1); + EXPECT_ACCEPTED(false); + thwart_rx_non_initial_requests(); + + btw("even though the TMSI is not acked, we can already find the subscr with it"); + vsub = vlr_subscr_find_by_tmsi(net->vlr, 0x03020100); + VERBOSE_ASSERT(vsub != NULL, == true, "%d"); + VERBOSE_ASSERT(strcmp(vsub->imsi, imsi), == 0, "%d"); + VERBOSE_ASSERT(vsub->tmsi_new, == 0x03020100, "0x%08x"); + VERBOSE_ASSERT(vsub->tmsi, == GSM_RESERVED_TMSI, "0x%08x"); + vlr_subscr_put(vsub); + + btw("MS sends TMSI Realloc Complete"); + ms_sends_msg("055b"); + + btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); clear_vlr(); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err index d6896023c..26ceb0d78 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err @@ -103,9 +103,39 @@ DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Removing from paren DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL -- sending LU Accept for MSISDN:42342 -DREF VLR subscr MSISDN:42342 usage increases to: 3 -DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +- 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 + lu_result_sent == 1 +- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl + llist_count(&net->subscr_conns) == 1 +msc_subscr_conn_is_accepted() == false + requests shall be thwarted +DRLL Dispatching 04.08 message, pdisc=3 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x03 msg_type=0x05 +DRLL Dispatching 04.08 message, pdisc=5 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x05 msg_type=0x33 +DRLL Dispatching 04.08 message, pdisc=6 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x06 msg_type=0x19 +DRLL Dispatching 04.08 message, pdisc=9 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x09 msg_type=0x01 +- even though the TMSI is not acked, we can already find the subscr with it +DREF VLR subscr MSISDN:42342 usage increases to: 2 + vsub != NULL == 1 + strcmp(vsub->imsi, imsi) == 0 + vsub->tmsi_new == 0x03020100 + vsub->tmsi == 0xffffffff +DREF VLR subscr MSISDN:42342 usage decreases to: 1 +- MS sends TMSI Realloc Complete + rx from MS: pdisc=0x05 msg_type=0x5b +DRLL Dispatching 04.08 message, pdisc=5 +DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 +DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK +DVLR lu_compl_vlr_fsm(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(901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000010650) @@ -124,13 +154,10 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated DRLL subscr MSISDN:42342: Freeing subscriber connection -DREF VLR subscr MSISDN:42342 usage decreases to: 2 +DREF VLR subscr MSISDN:42342 usage decreases to: 1 DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated -DREF VLR subscr MSISDN:42342 usage decreases to: 1 -<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 - LU was successful, and the conn has already been closed - lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 --- - after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector @@ -236,7 +263,7 @@ DREF VLR subscr MSISDN:42342 usage increases to: 2 llist_count(&vsub->cs.requests) == 0 DREF VLR subscr MSISDN:42342 usage increases to: 3 DMM Subscriber MSISDN:42342 not paged yet, start paging. - RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 0 + RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 0 strcmp(paging_expecting_imsi, imsi) == 0 DREF VLR subscr MSISDN:42342 usage increases to: 4 llist_count(&vsub->cs.requests) == 1 @@ -485,9 +512,39 @@ DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Removing from paren DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL -- sending LU Accept for MSISDN:42342 -DREF VLR subscr MSISDN:42342 usage increases to: 3 -DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +- 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 + lu_result_sent == 1 +- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl + llist_count(&net->subscr_conns) == 1 +msc_subscr_conn_is_accepted() == false + requests shall be thwarted +DRLL Dispatching 04.08 message, pdisc=3 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x03 msg_type=0x05 +DRLL Dispatching 04.08 message, pdisc=5 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x05 msg_type=0x33 +DRLL Dispatching 04.08 message, pdisc=6 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x06 msg_type=0x19 +DRLL Dispatching 04.08 message, pdisc=9 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x09 msg_type=0x01 +- even though the TMSI is not acked, we can already find the subscr with it +DREF VLR subscr MSISDN:42342 usage increases to: 2 + vsub != NULL == 1 + strcmp(vsub->imsi, imsi) == 0 + vsub->tmsi_new == 0x03020100 + vsub->tmsi == 0xffffffff +DREF VLR subscr MSISDN:42342 usage decreases to: 1 +- MS sends TMSI Realloc Complete + rx from MS: pdisc=0x05 msg_type=0x5b +DRLL Dispatching 04.08 message, pdisc=5 +DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 +DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK +DVLR lu_compl_vlr_fsm(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(901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000010650) @@ -506,13 +563,10 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated DRLL subscr MSISDN:42342: Freeing subscriber connection -DREF VLR subscr MSISDN:42342 usage decreases to: 2 +DREF VLR subscr MSISDN:42342 usage decreases to: 1 DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated -DREF VLR subscr MSISDN:42342 usage decreases to: 1 -<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 - LU was successful, and the conn has already been closed - lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 --- - after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector @@ -619,7 +673,7 @@ DREF VLR subscr MSISDN:42342 usage increases to: 2 llist_count(&vsub->cs.requests) == 0 DREF VLR subscr MSISDN:42342 usage increases to: 3 DMM Subscriber MSISDN:42342 not paged yet, start paging. - RAN_UTRAN_IU sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 0 + RAN_UTRAN_IU sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 0 strcmp(paging_expecting_imsi, imsi) == 0 DREF VLR subscr MSISDN:42342 usage increases to: 4 llist_count(&vsub->cs.requests) == 1 @@ -895,9 +949,39 @@ DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Removing from paren DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL -- sending LU Accept for MSISDN:42342 -DREF VLR subscr MSISDN:42342 usage increases to: 3 -DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +- 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 + lu_result_sent == 1 +- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl + llist_count(&net->subscr_conns) == 1 +msc_subscr_conn_is_accepted() == false + requests shall be thwarted +DRLL Dispatching 04.08 message, pdisc=3 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x03 msg_type=0x05 +DRLL Dispatching 04.08 message, pdisc=5 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x05 msg_type=0x33 +DRLL Dispatching 04.08 message, pdisc=6 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x06 msg_type=0x19 +DRLL Dispatching 04.08 message, pdisc=9 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x09 msg_type=0x01 +- even though the TMSI is not acked, we can already find the subscr with it +DREF VLR subscr MSISDN:42342 usage increases to: 2 + vsub != NULL == 1 + strcmp(vsub->imsi, imsi) == 0 + vsub->tmsi_new == 0x03020100 + vsub->tmsi == 0xffffffff +DREF VLR subscr MSISDN:42342 usage decreases to: 1 +- MS sends TMSI Realloc Complete + rx from MS: pdisc=0x05 msg_type=0x5b +DRLL Dispatching 04.08 message, pdisc=5 +DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 +DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK +DVLR lu_compl_vlr_fsm(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(901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000010650) @@ -916,13 +1000,10 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated DRLL subscr MSISDN:42342: Freeing subscriber connection -DREF VLR subscr MSISDN:42342 usage decreases to: 2 +DREF VLR subscr MSISDN:42342 usage decreases to: 1 DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated -DREF VLR subscr MSISDN:42342 usage decreases to: 1 -<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 - LU was successful, and the conn has already been closed - lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:42342 ===== test_umts_authen_resync_geran: SUCCESS @@ -1063,9 +1144,39 @@ DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Removing from paren DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Freeing instance DVLR sub_pres_vlr_fsm(901700000010650){SUB_PRES_VLR_S_DONE}: Deallocated DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL -- sending LU Accept for MSISDN:42342 -DREF VLR subscr MSISDN:42342 usage increases to: 3 -DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() +DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF +- 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 + lu_result_sent == 1 +- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl + llist_count(&net->subscr_conns) == 1 +msc_subscr_conn_is_accepted() == false + requests shall be thwarted +DRLL Dispatching 04.08 message, pdisc=3 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x03 msg_type=0x05 +DRLL Dispatching 04.08 message, pdisc=5 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x05 msg_type=0x33 +DRLL Dispatching 04.08 message, pdisc=6 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x06 msg_type=0x19 +DRLL Dispatching 04.08 message, pdisc=9 +DRLL subscr MSISDN:42342: Message not permitted for initial conn: pdisc=0x09 msg_type=0x01 +- even though the TMSI is not acked, we can already find the subscr with it +DREF VLR subscr MSISDN:42342 usage increases to: 2 + vsub != NULL == 1 + strcmp(vsub->imsi, imsi) == 0 + vsub->tmsi_new == 0x03020100 + vsub->tmsi == 0xffffffff +DREF VLR subscr MSISDN:42342 usage decreases to: 1 +- MS sends TMSI Realloc Complete + rx from MS: pdisc=0x05 msg_type=0x5b +DRLL Dispatching 04.08 message, pdisc=5 +DMM TMSI Reallocation Completed. Subscriber: MSISDN:42342 +DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK +DVLR lu_compl_vlr_fsm(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(901700000010650){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) DVLR lu_compl_vlr_fsm(901700000010650){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000010650) @@ -1084,13 +1195,10 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated DRLL subscr MSISDN:42342: Freeing subscriber connection -DREF VLR subscr MSISDN:42342 usage decreases to: 2 +DREF VLR subscr MSISDN:42342 usage decreases to: 1 DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated -DREF VLR subscr MSISDN:42342 usage decreases to: 1 -<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 - LU was successful, and the conn has already been closed - lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:42342 ===== test_umts_authen_resync_utran: SUCCESS -- cgit v1.2.3