properly receive BSSMAP Clear Complete and Iu Release Complete

When sending a BSSMAP Clear or Iu Release, do not immediately discard the conn,
but wait until a BSSMAP Clear Complete / Iu Release Complete has been received.

Hence we will no longer show in the log that an incoming Release/Clear Complete
belongs to an unknown subscriber, but will still be around to properly log the
release.

Related: OS#3122
Change-Id: Ie4c6aaba3866d6e5b98004e8870a215e8cf8ffc1

1 files changed, 25 insertions, 20 deletions

diff --git a/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
index a3950edc2..82786ff42 100644
--- a/tests/msc_vlr/msc_vlr_test_ms_timeout.err
+++ b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
@@ -82,6 +82,9 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_CN_CLOSE not permitted
 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
 - BSSAP Clear --RAN_GERAN_A--> MS
+- SUBSCR_CONN_TIMEOUT has passed, conn is gone.
+  bssap_clear_sent == 1
+- BSS sends BSSMAP Clear Complete
 DREF IMSI:901700000004620: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -100,8 +103,6 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 0
 DREF freeing VLR subscr IMSI:901700000004620
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
-- SUBSCR_CONN_TIMEOUT has passed, conn is gone.
-  bssap_clear_sent == 1
   llist_count(&net->subscr_conns) == 0
   lu_result_sent == 2
 ===== test_ms_timeout_lu_auth_resp: SUCCESS
@@ -241,6 +242,12 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage decreases to: 3
 - BSSAP Clear --RAN_GERAN_A--> MS
+DREF VLR subscr MSISDN:46071 usage decreases to: 2
+<-- 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
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:46071: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -251,14 +258,9 @@ 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
 DRLL MSISDN:46071: Freeing subscriber connection
-DREF VLR subscr MSISDN:46071 usage decreases to: 2
+DREF VLR subscr MSISDN:46071 usage decreases to: 1
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
-DREF VLR subscr MSISDN:46071 usage decreases to: 1
-<-- 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
 ---
 - after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector
@@ -327,6 +329,9 @@ DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_CN_CLOSE not permitted
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+- SUBSCR_CONN_TIMEOUT has passed, conn is gone.
+  bssap_clear_sent == 1
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:46071: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -343,8 +348,6 @@ DRLL MSISDN:46071: Freeing subscriber connection
 DREF VLR subscr MSISDN:46071 usage decreases to: 1
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
-- 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
@@ -444,6 +447,12 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage decreases to: 3
 - BSSAP Clear --RAN_GERAN_A--> MS
+DREF VLR subscr MSISDN:46071 usage decreases to: 2
+<-- 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
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:46071: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -454,14 +463,9 @@ 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
 DRLL MSISDN:46071: Freeing subscriber connection
-DREF VLR subscr MSISDN:46071 usage decreases to: 2
+DREF VLR subscr MSISDN:46071 usage decreases to: 1
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
-DREF VLR subscr MSISDN:46071 usage decreases to: 1
-<-- 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
 ---
 - an SMS is sent, MS is paged
@@ -533,16 +537,17 @@ DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Close event, cause 0
 DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING
 DREF unknown: MSC conn use + release == 2 (0x101)
 - BSSAP Clear --RAN_GERAN_A--> MS
-DREF unknown: MSC conn use - release == 1 (0x1)
-DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
+DREF unknown: MSC conn use - compl_l3 == 1 (0x100)
+  bssap_clear_sent == 1
+  paging_stopped == 1
+- BSS sends BSSMAP Clear Complete
+DREF unknown: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
 DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
 DRLL Freeing subscriber connection with NULL subscriber
 DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
-  bssap_clear_sent == 1
-  paging_stopped == 1
   llist_count(&net->subscr_conns) == 0
 ===== test_ms_timeout_paging: SUCCESS