From fd60925358a5daf08d7f3b509521b3c922527a7d Mon Sep 17 00:00:00 2001 From: Neels Hofmeyr Date: Sat, 22 Jul 2017 20:31:19 +0200 Subject: msc_vlr_tests: properly check BSSAP Clear and Iu Release Change-Id: Ice8125decc1a663d95ae70418e151bff559b983b --- openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.c | 36 +++++++++++ openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err | 68 ++++++++++---------- openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.c | 30 +++++++++ openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err | 56 ++++++++--------- openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.c | 22 +++++++ openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err | 44 ++++++------- openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.c | 4 ++ openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err | 8 +-- openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.c | 6 ++ openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err | 12 ++-- openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c | 26 ++++++++ openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err | 52 ++++++++-------- .../msc_vlr/msc_vlr_test_reject_concurrency.c | 30 +++++++-- .../msc_vlr/msc_vlr_test_reject_concurrency.err | 72 +++++++++++----------- openbsc/tests/msc_vlr/msc_vlr_test_rest.c | 13 ++++ openbsc/tests/msc_vlr/msc_vlr_test_rest.err | 23 +++---- openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c | 23 +++++++ openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err | 25 +++++--- openbsc/tests/msc_vlr/msc_vlr_tests.c | 13 ++++ openbsc/tests/msc_vlr/msc_vlr_tests.h | 32 ++++++++++ 20 files changed, 412 insertions(+), 183 deletions(-) diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.c b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.c index 22e549b2f..44e405232 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.c @@ -83,7 +83,9 @@ void test_gsm_authen() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -111,8 +113,10 @@ void test_gsm_authen() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -191,14 +195,18 @@ void test_gsm_authen() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -283,7 +291,9 @@ void test_gsm_authen_tmsi() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -318,8 +328,10 @@ void test_gsm_authen_tmsi() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -398,8 +410,10 @@ void test_gsm_authen_tmsi() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); @@ -408,7 +422,9 @@ void test_gsm_authen_tmsi() * deallocated and we no longer know the TMSI. This case is covered by * test_lu_unknown_tmsi(), so here I'd like to still have the TMSI. BTW("subscriber detaches, using TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "03020100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); */ @@ -449,7 +465,9 @@ void test_gsm_authen_tmsi() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -463,7 +481,9 @@ void test_gsm_authen_tmsi() vlr_subscr_put(vsub); BTW("subscriber detaches, using new TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "07060504"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -542,7 +562,9 @@ void test_gsm_authen_imei() thwart_rx_non_initial_requests(); btw("MS replies with an Identity Response"); + expect_bssap_clear(); ms_sends_msg("0559084a32244332244332"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -555,7 +577,9 @@ void test_gsm_authen_imei() vlr_subscr_put(vsub); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -654,7 +678,9 @@ void test_gsm_authen_tmsi_imei() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -667,7 +693,9 @@ void test_gsm_authen_tmsi_imei() vlr_subscr_put(vsub); BTW("subscriber detaches, using TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "03020100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -749,7 +777,9 @@ void test_gsm_milenage_authen() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000000156f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -780,8 +810,10 @@ void test_gsm_milenage_authen() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 42342\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -863,15 +895,19 @@ void test_gsm_milenage_authen() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130" "089910070000106005" /* IMSI */); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err index 73fd5d131..219d701b1 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err @@ -150,8 +150,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -159,6 +158,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -264,14 +264,14 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -411,8 +411,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -420,6 +419,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -435,10 +435,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_gsm_authen: SUCCESS @@ -628,14 +628,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - Subscriber has the new TMSI @@ -747,14 +747,14 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -894,8 +894,7 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -903,6 +902,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -1055,14 +1055,14 @@ DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - subscriber has the new TMSI @@ -1085,10 +1085,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_gsm_authen_tmsi: SUCCESS @@ -1276,14 +1276,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1304,10 +1304,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_gsm_authen_imei: SUCCESS @@ -1526,14 +1526,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - Subscriber has the IMEI and TMSI @@ -1554,10 +1554,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_gsm_authen_tmsi_imei: SUCCESS @@ -1697,8 +1697,7 @@ 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 DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -1706,6 +1705,7 @@ DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM 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 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1811,14 +1811,14 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from p DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -1958,8 +1958,7 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from p DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -1967,6 +1966,7 @@ DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -1982,10 +1982,10 @@ 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 msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_gsm_milenage_authen: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.c b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.c index 1ebf9c653..7ca22d907 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.c @@ -87,7 +87,9 @@ void test_ciph() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -124,8 +126,10 @@ void test_ciph() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -213,14 +217,18 @@ void test_ciph() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -310,7 +318,9 @@ void test_ciph_tmsi() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -355,8 +365,10 @@ void test_ciph_tmsi() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -444,14 +456,18 @@ void test_ciph_tmsi() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches, using TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "03020100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -536,7 +552,9 @@ void test_ciph_imei() thwart_rx_non_initial_requests(); btw("MS replies with an Identity Response"); + expect_bssap_clear(); ms_sends_msg("0559084a32244332244332"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -549,7 +567,9 @@ void test_ciph_imei() vlr_subscr_put(vsub); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -639,14 +659,18 @@ void test_ciph_imeisv() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -749,7 +773,9 @@ void test_ciph_tmsi_imei() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -762,7 +788,9 @@ void test_ciph_tmsi_imei() vlr_subscr_put(vsub); BTW("subscriber detaches, using TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "03020100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -799,7 +827,9 @@ void test_lu_unknown_tmsi() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err index 469bd816d..314556947 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err @@ -150,8 +150,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -159,6 +158,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -281,14 +281,14 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -445,8 +445,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -454,6 +453,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -469,10 +469,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_ciph: SUCCESS @@ -663,14 +663,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - Subscriber has the new TMSI @@ -799,14 +799,14 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -963,8 +963,7 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -972,6 +971,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -987,10 +987,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_ciph_tmsi: SUCCESS @@ -1178,14 +1178,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1206,10 +1206,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_ciph_imei: SUCCESS @@ -1399,8 +1399,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1408,6 +1407,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1424,10 +1424,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_ciph_imeisv: SUCCESS @@ -1646,14 +1646,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - Subscriber has the IMEI and TMSI @@ -1674,10 +1674,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_ciph_tmsi_imei: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.c b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.c index c4cf3534a..095da8172 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.c @@ -38,9 +38,11 @@ void test_hlr_rej_auth_info_unknown_imsi() btw("HLR sends _SEND_AUTH_INFO_ERROR = unknown IMSI"); auth_request_sent = false; + expect_bssap_clear(); gsup_rx("09" "010809710000004026f0" "020102", NULL); VERBOSE_ASSERT(auth_request_sent, == false, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -62,9 +64,11 @@ void test_hlr_rej_auth_info_net_fail() btw("HLR sends _SEND_AUTH_INFO_ERROR = net fail"); auth_request_sent = false; + expect_bssap_clear(); gsup_rx("09" "010809710000004026f0" "020111", NULL); VERBOSE_ASSERT(auth_request_sent, == false, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -118,7 +122,9 @@ void test_hlr_rej_auth_info_net_fail_no_reuse_tuples() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -145,9 +151,11 @@ void test_hlr_rej_auth_info_net_fail_no_reuse_tuples() btw("HLR sends _SEND_AUTH_INFO_ERROR = net fail"); auth_request_sent = false; + expect_bssap_clear(); gsup_rx("09" "010809710000004026f0" "020111", NULL); VERBOSE_ASSERT(auth_request_sent, == false, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -201,7 +209,9 @@ void test_hlr_rej_auth_info_unkown_imsi_no_reuse_tuples() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -229,9 +239,11 @@ void test_hlr_rej_auth_info_unkown_imsi_no_reuse_tuples() btw("HLR sends _SEND_AUTH_INFO_ERROR = unknown IMSI"); auth_request_sent = false; + expect_bssap_clear(); gsup_rx("09" "010809710000004026f0" "020102", NULL); VERBOSE_ASSERT(auth_request_sent, == false, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -255,6 +267,7 @@ void test_hlr_acc_but_no_auth_tuples() btw("from HLR, rx _SEND_AUTH_INFO_RESULT but it lacks auth tuples"); auth_request_sent = false; + expect_bssap_clear(); gsup_rx("0a" /* imsi */ "0108" "09710000004026f0" @@ -262,6 +275,7 @@ void test_hlr_acc_but_no_auth_tuples() ,NULL); VERBOSE_ASSERT(auth_request_sent, == false, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -315,7 +329,9 @@ void test_hlr_rej_auth_info_net_fail_reuse_tuples() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -357,7 +373,9 @@ void test_hlr_rej_auth_info_net_fail_reuse_tuples() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -379,9 +397,11 @@ void test_hlr_rej_lu() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR sends UPDATE_LOCATION_ERROR"); + expect_bssap_clear(); gsup_rx("05" "010809710000004026f0" "020102", NULL); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -400,7 +420,9 @@ void test_hlr_no_insert_data() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR sends only _UPDATE_LOCATION_RESULT, no INSERT DATA"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); /* TODO should we wait for OSMO_GSUP_MSGT_INSERT_DATA_REQUEST? */ diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err index 4b16ac113..766fb59a8 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err @@ -56,8 +56,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 @@ -68,6 +67,7 @@ DREF freeing VLR subscr IMSI:901700000004620 <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: vlr_gsupc_read_cb() returns 0 auth_request_sent == 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_hlr_rej_auth_info_unknown_imsi: SUCCESS @@ -132,8 +132,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 @@ -144,6 +143,7 @@ DREF freeing VLR subscr IMSI:901700000004620 <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: vlr_gsupc_read_cb() returns 0 auth_request_sent == 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_hlr_rej_auth_info_net_fail: SUCCESS @@ -285,8 +285,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -294,6 +293,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -433,8 +433,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -442,6 +441,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -586,8 +586,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -595,6 +594,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -660,8 +660,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -671,6 +670,7 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: vlr_gsupc_read_cb() returns 0 auth_request_sent == 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:46071 ===== test_hlr_rej_auth_info_net_fail_no_reuse_tuples: SUCCESS @@ -813,8 +813,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -822,6 +821,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -888,8 +888,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -899,6 +898,7 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: vlr_gsupc_read_cb() returns 0 auth_request_sent == 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:46071 ===== test_hlr_rej_auth_info_unkown_imsi_no_reuse_tuples: SUCCESS @@ -963,8 +963,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 @@ -975,6 +974,7 @@ DREF freeing VLR subscr IMSI:901700000004620 <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0 auth_request_sent == 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_hlr_acc_but_no_auth_tuples: SUCCESS @@ -1042,8 +1042,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 @@ -1053,6 +1052,7 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 DREF freeing VLR subscr IMSI:901700000004620 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_ERROR: vlr_gsupc_read_cb() returns 0 lu_result_sent == 2 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_hlr_rej_lu: SUCCESS @@ -1142,8 +1142,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 2 @@ -1151,6 +1150,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.c b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.c index 2872f0cf4..c2f17c85f 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.c @@ -53,8 +53,10 @@ void test_hlr_timeout_lu_auth_info() EXPECT_CONN_COUNT(1); fake_time_passes(1, 235); EXPECT_CONN_COUNT(1); + expect_bssap_clear(); fake_time_passes(1, 235); btw("SUBSCR_CONN_TIMEOUT has passed, conn is gone."); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); @@ -98,8 +100,10 @@ void test_hlr_timeout_lu_upd_loc_result() fake_time_passes(1, 235); EXPECT_CONN_COUNT(1); VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); + expect_bssap_clear(); fake_time_passes(1, 235); btw("SUBSCR_CONN_TIMEOUT has passed, conn is gone."); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err index 0fb328e30..e13643fa3 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err @@ -64,8 +64,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 @@ -75,6 +74,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Received Event SUBSCR_CONN_E_CN_CLOSE DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Event SUBSCR_CONN_E_CN_CLOSE not permitted - SUBSCR_CONN_TIMEOUT has passed, conn is gone. + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 lu_result_sent == 2 ===== test_hlr_timeout_lu_auth_info: SUCCESS @@ -166,8 +166,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 0 @@ -177,6 +176,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Received Event SUBSCR_CONN_E_CN_CLOSE DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Event SUBSCR_CONN_E_CN_CLOSE not permitted - SUBSCR_CONN_TIMEOUT has passed, conn is gone. + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 lu_result_sent == 2 ===== test_hlr_timeout_lu_upd_loc_result: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.c b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.c index 47ca9678f..d8a3a314e 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.c @@ -73,8 +73,10 @@ void test_ms_timeout_lu_auth_resp() fake_time_passes(1, 235); EXPECT_CONN_COUNT(1); VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); + expect_bssap_clear(); fake_time_passes(1, 235); btw("SUBSCR_CONN_TIMEOUT has passed, conn is gone."); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); @@ -132,7 +134,9 @@ void test_ms_timeout_cm_auth_resp() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -167,8 +171,10 @@ void test_ms_timeout_cm_auth_resp() fake_time_passes(1, 235); EXPECT_CONN_COUNT(1); VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d"); + expect_bssap_clear(); fake_time_passes(1, 235); btw("SUBSCR_CONN_TIMEOUT has passed, conn is gone."); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); VERBOSE_ASSERT(cm_service_result_sent, == RES_REJECT, "%d"); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err index 5422bec3b..fe6bbb066 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err @@ -84,8 +84,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF IMSI:901700000004620: MSC conn use - 1 == 0 DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 @@ -95,6 +94,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Received Event SUBSCR_CONN_E_CN_CLOSE DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Event SUBSCR_CONN_E_CN_CLOSE not permitted - SUBSCR_CONN_TIMEOUT has passed, conn is gone. + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 lu_result_sent == 2 ===== test_ms_timeout_lu_auth_resp: SUCCESS @@ -236,8 +236,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -245,6 +244,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -319,8 +319,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 @@ -329,6 +328,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Received Event SUBSCR_CONN_E_CN_CLOSE DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Event SUBSCR_CONN_E_CN_CLOSE not permitted - SUBSCR_CONN_TIMEOUT has passed, conn is gone. + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 cm_service_result_sent == 2 DREF freeing VLR subscr MSISDN:46071 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c index f5e2e2b62..34e392e72 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c @@ -53,10 +53,12 @@ void test_no_authen() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); BTW("after a while, a new conn sends a CM Service Request"); @@ -70,8 +72,10 @@ void test_no_authen() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -140,14 +144,18 @@ void test_no_authen() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -200,7 +208,9 @@ void test_no_authen_tmsi() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -224,7 +234,9 @@ void test_no_authen_tmsi() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -293,8 +305,10 @@ void test_no_authen_tmsi() btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); @@ -343,7 +357,9 @@ void test_no_authen_tmsi() vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -357,7 +373,9 @@ void test_no_authen_tmsi() vlr_subscr_put(vsub); BTW("subscriber detaches, using new TMSI"); + expect_bssap_clear(); ms_sends_msg("050130" "05f4" "07060504"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -406,7 +424,9 @@ void test_no_authen_imei() thwart_rx_non_initial_requests(); btw("MS replies with an Identity Response"); + expect_bssap_clear(); ms_sends_msg("0559084a32244332244332"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -419,7 +439,9 @@ void test_no_authen_imei() vlr_subscr_put(vsub); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -478,7 +500,9 @@ void test_no_authen_tmsi_imei() thwart_rx_non_initial_requests(); btw("MS sends TMSI Realloc Complete"); + expect_bssap_clear(); ms_sends_msg("055b"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -492,7 +516,9 @@ void test_no_authen_tmsi_imei() vlr_subscr_put(vsub); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err index a2f001e42..cf044f17b 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err @@ -103,8 +103,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -114,6 +113,7 @@ DREF VLR subscr MSISDN:46071 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 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 --- - after a while, a new conn sends a CM Service Request @@ -178,8 +178,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -187,6 +186,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -287,8 +287,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -296,6 +295,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -311,10 +311,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_no_authen: SUCCESS @@ -457,14 +457,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - Subscriber has the new TMSI @@ -537,14 +537,14 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -645,8 +645,7 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent S DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -654,6 +653,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -790,14 +790,14 @@ DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 - subscriber has the new TMSI @@ -820,10 +820,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_no_authen_tmsi: SUCCESS @@ -964,14 +964,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -992,10 +992,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_no_authen_imei: SUCCESS @@ -1160,14 +1160,14 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1189,10 +1189,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_no_authen_tmsi_imei: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.c b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.c index 15988584a..2377c19b3 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.c @@ -39,7 +39,9 @@ void test_reject_2nd_conn() btw("Another Location Update Request from the same subscriber on another connection is rejected"); conn1 = g_conn; g_conn = NULL; + expect_bssap_clear(); ms_sends_msg("050802008168000130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); EXPECT_CONN_COUNT(1); @@ -53,7 +55,9 @@ void test_reject_2nd_conn() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -83,7 +87,9 @@ void _normal_lu_part2() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -164,7 +170,7 @@ void _paging_resp_part1() EXPECT_CONN_COUNT(1); } -void _paging_resp_part2(int expect_conn_count) +void _paging_resp_part2(int expect_conn_count, bool expect_clear) { btw("MS replies with CP-ACK for received SMS"); ms_sends_msg("8904"); @@ -172,8 +178,12 @@ void _paging_resp_part2(int expect_conn_count) btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + if (expect_clear) + expect_bssap_clear(); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + if (expect_clear) + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("SMS is done"); EXPECT_CONN_COUNT(expect_conn_count); @@ -251,7 +261,9 @@ void test_reject_lu_during_cm() EXPECT_CONN_COUNT(1); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -272,7 +284,9 @@ void test_reject_cm_during_cm() EXPECT_CONN_COUNT(1); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -293,7 +307,9 @@ void test_reject_paging_resp_during_cm() BTW("The original CM Service Request can conclude"); btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); + expect_bssap_clear(); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -313,7 +329,7 @@ void test_reject_paging_resp_during_paging_resp() BTW("MS sends another erratic Paging Response which is dropped silently"); ms_sends_msg("06270703305882089910070000006402"); - _paging_resp_part2(0); + _paging_resp_part2(0, true); clear_vlr(); comment_end(); @@ -333,13 +349,13 @@ void test_reject_lu_during_paging_resp() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); EXPECT_CONN_COUNT(1); - _paging_resp_part2(0); + _paging_resp_part2(0, true); clear_vlr(); comment_end(); } -void test_reject_cm_during_paging_resp() +void test_accept_cm_during_paging_resp() { comment_start(); @@ -354,10 +370,12 @@ void test_reject_cm_during_paging_resp() EXPECT_CONN_COUNT(1); VERBOSE_ASSERT(g_conn->received_cm_service_request, == true, "%d"); - _paging_resp_part2(1); + _paging_resp_part2(1, false); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -373,7 +391,7 @@ msc_vlr_test_func_t msc_vlr_tests[] = { test_reject_cm_during_cm, test_reject_paging_resp_during_cm, test_reject_lu_during_paging_resp, - test_reject_cm_during_paging_resp, + test_accept_cm_during_paging_resp, test_reject_paging_resp_during_paging_resp, NULL }; 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 ae3c87b78..aed55ad63 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err @@ -64,8 +64,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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=unknown, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -73,6 +72,7 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DRR 901700000004620: internal error during Location Updating attempt DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 lu_result_sent == 2 llist_count(&net->subscr_conns) == 1 --- @@ -135,8 +135,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -144,6 +143,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -259,8 +259,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -268,6 +267,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -389,8 +389,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -398,6 +397,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -514,8 +514,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -523,6 +522,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -628,8 +628,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -637,6 +636,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -706,8 +706,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -718,6 +717,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 0 DREF freeing VLR subscr MSISDN:46071 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_reject_lu_during_cm: SUCCESS @@ -820,8 +820,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -829,6 +828,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -900,8 +900,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -912,6 +911,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 0 DREF freeing VLR subscr MSISDN:46071 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_reject_cm_during_cm: SUCCESS @@ -1014,8 +1014,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1023,6 +1022,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1102,14 +1102,14 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:46071 @@ -1214,8 +1214,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1223,6 +1222,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1327,8 +1327,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -1336,6 +1335,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:46071 @@ -1344,7 +1344,7 @@ DREF freeing VLR subscr MSISDN:46071 full talloc report on 'msgb' (total 0 bytes in 1 blocks) talloc_total_blocks(tall_bsc_ctx) == 9 -===== test_reject_cm_during_paging_resp +===== test_accept_cm_during_paging_resp --- - Subscriber does a normal LU - Location Update Request @@ -1440,8 +1440,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1449,6 +1448,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1569,8 +1569,7 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SU DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -1581,8 +1580,9 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 0 DREF freeing VLR subscr MSISDN:46071 + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 -===== test_reject_cm_during_paging_resp: SUCCESS +===== test_accept_cm_during_paging_resp: SUCCESS full talloc report on 'msgb' (total 0 bytes in 1 blocks) talloc_total_blocks(tall_bsc_ctx) == 9 @@ -1683,8 +1683,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -1692,6 +1691,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -1795,8 +1795,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -1804,6 +1803,7 @@ DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:46071 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_rest.c b/openbsc/tests/msc_vlr/msc_vlr_test_rest.c index 5ccc951be..c5f7fcfb9 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_rest.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_rest.c @@ -45,6 +45,7 @@ void test_early_stage() btw("fake: acceptance"); g_conn->vsub = vlr_subscr_alloc(net->vlr); + g_conn->via_ran = RAN_GERAN_A; OSMO_ASSERT(g_conn->vsub); /* mark as silent call so it sticks around */ g_conn->silent_call = 1; @@ -53,7 +54,9 @@ void test_early_stage() EXPECT_ACCEPTED(true); btw("CLOSE event marks conn_fsm as released and frees the conn"); + expect_bssap_clear(); osmo_fsm_inst_dispatch(g_conn->conn_fsm, SUBSCR_CONN_E_CN_CLOSE, NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -65,7 +68,9 @@ void test_cm_service_without_lu() comment_start(); btw("CM Service Request without a prior Location Updating"); + expect_bssap_clear(); ms_sends_msg("05247803305886089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("conn was released"); EXPECT_CONN_COUNT(0); @@ -98,7 +103,9 @@ void test_two_lu() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); @@ -126,14 +133,18 @@ void test_two_lu() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_bssap_clear(); ms_sends_msg("050130089910070000006402"); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -170,7 +181,9 @@ void test_lu_unknown_tmsi() VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d"); btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT"); + expect_bssap_clear(); gsup_rx("06010809710000004026f0", NULL); + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); btw("LU was successful, and the conn has already been closed"); VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d"); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_rest.err b/openbsc/tests/msc_vlr/msc_vlr_test_rest.err index d9da8ba5d..89f988de4 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_rest.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_rest.err @@ -28,13 +28,14 @@ DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_C DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event. -DMM unknown: Unknown RAN type, cannot tx release/clear +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL subscr unknown: Freeing subscriber connection DREF VLR subscr unknown usage decreases to: 0 DREF freeing VLR subscr unknown DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Deallocated + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_early_stage: SUCCESS @@ -70,13 +71,13 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from p 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=unknown, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 - conn was released llist_count(&net->subscr_conns) == 0 ===== test_cm_service_without_lu: SUCCESS @@ -189,8 +190,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -198,6 +198,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -304,8 +305,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -313,6 +313,7 @@ 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 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 @@ -329,10 +330,10 @@ 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. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_two_lu: SUCCESS @@ -469,8 +470,7 @@ DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSM DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:46071: MSC conn use - 1 == 0 DRLL subscr MSISDN:46071: Freeing subscriber connection DREF VLR subscr MSISDN:46071 usage decreases to: 2 @@ -478,6 +478,7 @@ DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Deallocated DREF VLR subscr MSISDN:46071 usage decreases to: 1 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed lu_result_sent == 1 llist_count(&net->subscr_conns) == 0 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 d026f0229..1175bf875 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.c @@ -23,6 +23,19 @@ #include "msc_vlr_tests.h" +#define ASSERT_RELEASE_CLEAR(via_ran) \ + switch (via_ran) { \ + case RAN_GERAN_A: \ + VERBOSE_ASSERT(bssap_clear_sent, == true, "%d"); \ + break; \ + case RAN_UTRAN_IU: \ + VERBOSE_ASSERT(iu_release_sent, == true, "%d"); \ + break; \ + default: \ + OSMO_ASSERT(false); \ + break; \ + } + void _test_umts_authen(enum ran_type via_ran) { struct vlr_subscr *vsub; @@ -167,7 +180,9 @@ void _test_umts_authen(enum ran_type via_ran) vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_release_clear(via_ran); ms_sends_msg("055b"); + ASSERT_RELEASE_CLEAR(via_ran); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); @@ -210,8 +225,10 @@ void _test_umts_authen(enum ran_type via_ran) btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 42342\r"); + expect_release_clear(via_ran); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); OSMO_ASSERT(dtap_tx_confirmed); + ASSERT_RELEASE_CLEAR(via_ran); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -287,15 +304,19 @@ void _test_umts_authen(enum ran_type via_ran) btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that"); dtap_expect_tx("0904"); + expect_release_clear(via_ran); ms_sends_msg("890106020041020000"); VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); + ASSERT_RELEASE_CLEAR(via_ran); btw("SMS is done, conn is gone"); EXPECT_CONN_COUNT(0); BTW("subscriber detaches"); + expect_release_clear(via_ran); ms_sends_msg("050130" "089910070000106005" /* IMSI */); + ASSERT_RELEASE_CLEAR(via_ran); EXPECT_CONN_COUNT(0); clear_vlr(); @@ -527,7 +548,9 @@ void _test_umts_authen_resync(enum ran_type via_ran) vlr_subscr_put(vsub); btw("MS sends TMSI Realloc Complete"); + expect_release_clear(via_ran); ms_sends_msg("055b"); + ASSERT_RELEASE_CLEAR(via_ran); btw("LU was successful, and the conn has already been closed"); EXPECT_CONN_COUNT(0); 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 a40fbd7e8..24edb895f 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err @@ -164,14 +164,14 @@ 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 DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 --- @@ -277,14 +277,14 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from p DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + bssap_clear_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -425,8 +425,7 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from p DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated @@ -434,6 +433,7 @@ DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 dtap_tx_confirmed == 1 + bssap_clear_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -449,10 +449,10 @@ 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 msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + bssap_clear_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_umts_authen_geran: SUCCESS @@ -645,6 +645,7 @@ DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + iu_release_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 --- @@ -768,6 +769,7 @@ DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + iu_release_sent == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -927,6 +929,7 @@ DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 dtap_tx_confirmed == 1 + iu_release_sent == 1 - SMS is done, conn is gone llist_count(&net->subscr_conns) == 0 --- @@ -945,6 +948,7 @@ DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directl - Iu Release --RAN_UTRAN_IU--> MS DREF unknown: MSC conn use - 1 == 0 DRLL Freeing subscriber connection with NULL subscriber + iu_release_sent == 1 llist_count(&net->subscr_conns) == 0 ===== test_umts_authen_utran: SUCCESS @@ -1147,14 +1151,14 @@ 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 DMM msc_subscr_conn_close(vsub=MSISDN:42342, cause=2): no conn fsm, releasing directly without release event. -- Sending clear command to BSC (conn_id=0) - +- BSSAP Clear --RAN_GERAN_A--> MS DREF MSISDN:42342: MSC conn use - 1 == 1 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + bssap_clear_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:42342 @@ -1379,6 +1383,7 @@ DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated DREF MSISDN:42342: MSC conn use - 1 == 0 DRLL subscr MSISDN:42342: Freeing subscriber connection DREF VLR subscr MSISDN:42342 usage decreases to: 1 + iu_release_sent == 1 - LU was successful, and the conn has already been closed llist_count(&net->subscr_conns) == 0 DREF freeing VLR subscr MSISDN:42342 diff --git a/openbsc/tests/msc_vlr/msc_vlr_tests.c b/openbsc/tests/msc_vlr/msc_vlr_tests.c index 9c3d6cea7..4af4e1bde 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_tests.c +++ b/openbsc/tests/msc_vlr/msc_vlr_tests.c @@ -59,6 +59,10 @@ const char *auth_request_expect_autn; bool cipher_mode_cmd_sent; bool cipher_mode_cmd_sent_with_imeisv; +bool iu_release_expected = false; +bool iu_release_sent = false; +bool bssap_clear_expected = false; +bool bssap_clear_sent = false; struct msgb *msgb_from_hex(const char *label, uint16_t size, const char *hex) { @@ -332,6 +336,11 @@ void clear_vlr() next_rand_byte = 0; + iu_release_expected = false; + iu_release_sent = false; + bssap_clear_expected = false; + bssap_clear_sent = false; + osmo_gettimeofday_override = false; } @@ -474,6 +483,10 @@ int __real_iu_tx_release(struct ue_conn_ctx *ctx, const struct RANAP_Cause *caus int __wrap_iu_tx_release(struct ue_conn_ctx *ctx, const struct RANAP_Cause *cause) { btw("Iu Release --%s--> MS", ran_type_name(RAN_UTRAN_IU)); + OSMO_ASSERT(iu_release_expected); + iu_release_expected = false; + iu_release_sent = true; + return 0; } /* override, requires '-Wl,--wrap=a_iface_tx_dtap' */ diff --git a/openbsc/tests/msc_vlr/msc_vlr_tests.h b/openbsc/tests/msc_vlr/msc_vlr_tests.h index ae0f83c9a..c2c5a58a7 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_tests.h +++ b/openbsc/tests/msc_vlr/msc_vlr_tests.h @@ -79,6 +79,38 @@ extern bool cipher_mode_cmd_sent_with_imeisv; extern bool paging_sent; extern bool paging_stopped; +extern bool iu_release_expected; +extern bool iu_release_sent; +extern bool bssap_clear_expected; +extern bool bssap_clear_sent; + +static inline void expect_iu_release() +{ + iu_release_expected = true; + iu_release_sent = false; +} + +static inline void expect_bssap_clear() +{ + bssap_clear_expected = true; + bssap_clear_sent = false; +} + +static inline void expect_release_clear(enum ran_type via_ran) +{ + switch (via_ran) { + case RAN_GERAN_A: + expect_bssap_clear(); + return; + case RAN_UTRAN_IU: + expect_iu_release(); + return; + default: + OSMO_ASSERT(false); + break; + } +} + struct msc_vlr_test_cmdline_opts { bool verbose; int run_test_nr; -- cgit v1.2.3