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, 86 insertions, 67 deletions

diff --git a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
index 9d9026063..2d5670d34 100644
--- a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
+++ b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
@@ -155,6 +155,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
@@ -165,14 +171,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
@@ -297,6 +298,9 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  bssap_clear_sent == 1
+- all requests serviced, conn has been released
+- 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
@@ -309,8 +313,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
-  bssap_clear_sent == 1
-- all requests serviced, conn has been released
   llist_count(&net->subscr_conns) == 0
 ---
 - an SMS is sent, MS is paged
@@ -468,6 +470,10 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  dtap_tx_confirmed == 1
+  bssap_clear_sent == 1
+- SMS is done, conn is gone
+- 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
@@ -480,9 +486,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
-  dtap_tx_confirmed == 1
-  bssap_clear_sent == 1
-- SMS is done, conn is gone
   llist_count(&net->subscr_conns) == 0
 ---
 - subscriber detaches
@@ -502,15 +505,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_ciph: SUCCESS
 
@@ -703,8 +707,11 @@ DREF MSISDN:46071: MSC conn use + release == 2 (0x102)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - release == 1 (0x2)
-DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
+DREF MSISDN:46071: MSC conn use - dtap == 1 (0x100)
+  bssap_clear_sent == 1
+- LU was successful, and the conn has already been closed
+- 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
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
@@ -717,8 +724,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
-  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
 DREF VLR subscr MSISDN:46071 usage increases to: 2
@@ -850,6 +855,9 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  bssap_clear_sent == 1
+- all requests serviced, conn has been released
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:46071: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -862,8 +870,6 @@ DRLL MSISDN:46071: Freeing subscriber connection
 DREF VLR subscr MSISDN:46071 usage decreases to: 1
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
-  bssap_clear_sent == 1
-- all requests serviced, conn has been released
   llist_count(&net->subscr_conns) == 0
 ---
 - an SMS is sent, MS is paged
@@ -1021,6 +1027,10 @@ DREF MSISDN:46071: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  dtap_tx_confirmed == 1
+  bssap_clear_sent == 1
+- SMS is done, conn is gone
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:46071: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -1033,9 +1043,6 @@ DRLL MSISDN:46071: Freeing subscriber connection
 DREF VLR subscr MSISDN:46071 usage decreases to: 1
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
-  dtap_tx_confirmed == 1
-  bssap_clear_sent == 1
-- SMS is done, conn is gone
   llist_count(&net->subscr_conns) == 0
 ---
 - subscriber detaches, using TMSI
@@ -1055,15 +1062,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_ciph_tmsi: SUCCESS
 
@@ -1253,8 +1261,12 @@ DREF MSISDN:46071: MSC conn use + release == 2 (0x102)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - release == 1 (0x2)
-DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
+DREF MSISDN:46071: MSC conn use - dtap == 1 (0x100)
+  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
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
@@ -1267,9 +1279,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
-  bssap_clear_sent == 1
-- LU was successful, and the conn has already been closed
-  lu_result_sent == 1
   llist_count(&net->subscr_conns) == 0
 - Subscriber has the IMEI
 DREF VLR subscr MSISDN:46071 usage increases to: 2
@@ -1293,15 +1302,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_ciph_imei: SUCCESS
 
@@ -1483,6 +1493,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
@@ -1493,14 +1509,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
 ---
 - subscriber detaches
@@ -1520,15 +1531,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_ciph_imeisv: SUCCESS
 
@@ -1750,8 +1762,11 @@ DREF MSISDN:46071: MSC conn use + release == 2 (0x102)
 DREF VLR subscr MSISDN:46071 usage increases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - release == 1 (0x2)
-DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
+DREF MSISDN:46071: MSC conn use - dtap == 1 (0x100)
+  bssap_clear_sent == 1
+- LU was successful, and the conn has already been closed
+- 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
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
@@ -1764,8 +1779,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
-  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
 DREF VLR subscr MSISDN:46071 usage increases to: 2
@@ -1790,15 +1803,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_ciph_tmsi_imei: SUCCESS
 
@@ -1948,6 +1962,12 @@ DREF MSISDN:42342: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage decreases to: 3
 - BSSAP Clear --RAN_GERAN_A--> MS
+DREF VLR subscr MSISDN:42342 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:42342: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -1958,14 +1978,9 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cau
 DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance
 DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated
 DRLL MSISDN:42342: Freeing subscriber connection
-DREF VLR subscr MSISDN:42342 usage decreases to: 2
+DREF VLR subscr MSISDN:42342 usage decreases to: 1
 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
 ---
 - after a while, a new conn sends a CM Service Request. VLR responds with *UMTS AKA* Auth Req, 2nd auth vector
@@ -2080,6 +2095,9 @@ DREF MSISDN:42342: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:42342 usage increases to: 3
 DREF VLR subscr MSISDN:42342 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  bssap_clear_sent == 1
+- all requests serviced, conn has been released
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:42342: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -2092,8 +2110,6 @@ DRLL MSISDN:42342: Freeing subscriber connection
 DREF VLR subscr MSISDN:42342 usage decreases to: 1
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated
-  bssap_clear_sent == 1
-- all requests serviced, conn has been released
   llist_count(&net->subscr_conns) == 0
 ---
 - an SMS is sent, MS is paged
@@ -2241,6 +2257,10 @@ DREF MSISDN:42342: MSC conn use + release == 1 (0x100)
 DREF VLR subscr MSISDN:42342 usage increases to: 3
 DREF VLR subscr MSISDN:42342 usage decreases to: 2
 - BSSAP Clear --RAN_GERAN_A--> MS
+  dtap_tx_confirmed == 1
+  bssap_clear_sent == 1
+- SMS is done, conn is gone
+- BSS sends BSSMAP Clear Complete
 DREF MSISDN:42342: MSC conn use - release == 0 (0x0)
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -2253,9 +2273,6 @@ DRLL MSISDN:42342: Freeing subscriber connection
 DREF VLR subscr MSISDN:42342 usage decreases to: 1
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance
 DMM Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated
-  dtap_tx_confirmed == 1
-  bssap_clear_sent == 1
-- SMS is done, conn is gone
   llist_count(&net->subscr_conns) == 0
 ---
 - subscriber detaches
@@ -2275,15 +2292,16 @@ 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
+- 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
   llist_count(&net->subscr_conns) == 0
 ===== test_gsm_ciph_in_umts_env: SUCCESS
 
@@ -2369,8 +2387,10 @@ DREF IMSI:901700000004620: MSC conn use + release == 2 (0x102)
 DREF VLR subscr IMSI:901700000004620 usage increases to: 2
 DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
 - BSSAP Clear --RAN_GERAN_A--> MS
-DREF IMSI:901700000004620: MSC conn use - release == 1 (0x2)
-DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0)
+DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x100)
+  lu_result_sent == 2
+- 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
 DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
@@ -2384,7 +2404,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
-  lu_result_sent == 2
   llist_count(&net->subscr_conns) == 0
 ===== test_a5_3_not_supported: SUCCESS