refactor subscr_conn and subscr_conn_fsm de-/alloc
Refactor:
1. Glue the gsm_subscriber_connection alloc to the subscr_conn_fsm.
2. Add separate AUTH_CIPH state to the FSM.
3. Use conn->use_count to trigger conn release.
4. Add separate RELEASING state to the FSM.
5. Add rate counters for each of the three Complete Layer 3 types.
Details:
1. Glue the gsm_subscriber_connection alloc to the subscr_conn_fsm.
Historically, a gsm_subscriber_connection was allocated in libbsc land, and
only upon Complete Layer 3 did libmsc add the fsm instance. After splitting
openbsc.git into a separate osmo-msc, this is no longer necessary, hence:
Closely tie gsm_subscriber_connection allocation to the subscr_conn_fsm
instance: talloc the conn as a child of the FSM instance, and discard the conn
as soon as the FSM terminates.
2. Add separate AUTH_CIPH state to the FSM.
Decoding the Complete Layer 3 message is distinctly separate from waiting for
the VLR FSMs to conclude. Use the NEW state as "we don't know if this is a
valid message yet", and the AUTH_CIPH state as "evaluating, don't release".
A profound effect of this: should we for any odd reason fail to leave the FSM's
NEW state, the conn will be released right at the end of msc_compl_l3(),
without needing to trigger release in each code path.
3. Use conn->use_count to trigger conn release.
Before, the FSM itself would hold a use count on the conn, and hence we would
need to ask it whether it is ready to release the conn yet by dispatching
events, to achieve a use_count decrement.
Instead, unite the FSM instance and conn, and do not hold a use count by the
FSM. Hence, trigger an FSM "UNUSED" event only when the use_count reaches zero.
As long as use counts are done correctly, the FSM will terminate correctly.
These exceptions:
- The new AUTH_CIPH state explicitly ignores UNUSED events, since we expect the
use count to reach zero while evaluating Authentication and Ciphering. (I
experimented with holding a use count by AUTH_CIPH onenter() and releasing by
onleave(), but the use count and thus the conn are released before the next
state can initiate transactions that would increment the use count again.
Same thing for the VLR FSMs holding a use count, they should be done before
we advance to the next state. The easiest is to simply expect zero use count
during the AUTH_CIPH state.)
- A CM Service Request means that even though the MSC would be through with all
it wants to do, we shall still wait for a request to follow from the MS.
Hence the FSM holds a use count on itself while a CM Service is pending.
- While waiting for a Release/Clear Complete, the FSM holds a use count on
itself.
4. Add separate RELEASING state to the FSM.
If we decide to release for other reasons than a use count reaching zero, we
still need to be able to wait for the msc_dtap() use count on the conn to
release.
(An upcoming patch will further use the RELEASING state to properly wait for
Clear Complete / Release Complete messages.)
5. Add rate counters for each of the three Complete Layer 3 types.
Besides LU, also count CM Service Request and Paging Response
acceptance/rejections. Without these counters, only very few of the auth+ciph
outcomes actually show in the counters.
Related: OS#3122
Change-Id: I55feb379e176a96a831e105b86202b17a0ffe889
diff --git a/tests/msc_vlr/msc_vlr_test_rest.err b/tests/msc_vlr/msc_vlr_test_rest.err
index 5d5e1ec..2f09760 100644
--- a/tests/msc_vlr/msc_vlr_test_rest.err
+++ b/tests/msc_vlr/msc_vlr_test_rest.err
@@ -5,12 +5,9 @@
- NULL conn
msc_subscr_conn_is_accepted() == false
- freshly allocated conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
msc_subscr_conn_is_accepted() == false
- conn_fsm present, in state NEW
-DREF unknown: MSC conn use + fsm == 1 (0x4)
-DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Allocated
-DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
-DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
@@ -23,21 +20,28 @@
DRLL subscr unknown: Message not permitted for initial conn: SMS:0x01
- fake: acceptance
DREF VLR subscr unknown usage increases to: 1
-DMM Subscr_Conn(test){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
+DMM Subscr_Conn{SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: silent call still active
llist_count(&net->subscr_conns) == 1
msc_subscr_conn_is_accepted() == true
- CLOSE event marks conn_fsm as released and frees the conn
-DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_CLOSE
-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 Subscr_Conn{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_CLOSE
+DMM Subscr_Conn{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
+DREF unknown: MSC conn use + release == 1 (0x100)
+DREF VLR subscr unknown usage increases to: 2
+DREF VLR subscr unknown usage decreases to: 1
- BSSAP Clear --RAN_GERAN_A--> MS
-DREF unknown: MSC conn use - fsm == 0 (0x0)
-DRLL subscr unknown: Freeing subscriber connection
+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)
+DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: subscr_conn_fsm_has_active_transactions: silent call still active
+DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocating despite active transactions
+DRLL 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
+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_early_stage: SUCCESS
@@ -49,13 +53,10 @@
- CM Service Request without a prior Location Updating
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
new conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
-DREF unknown: MSC conn use + fsm == 2 (0x5)
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from CM_SERVICE_REQ
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
@@ -66,19 +67,23 @@
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_UNIDENT_SUBSCR
- sending CM Service Reject for unknown, result VLR_PR_ARQ_RES_UNIDENT_SUBSCR
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED
+DMM Subscr_Conn(901700000004620){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)
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_COMPLETE_LAYER_3 not permitted
+DREF unknown: MSC conn use - compl_l3 == 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)
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
-DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
-- BSSAP Clear --RAN_GERAN_A--> MS
-DREF unknown: MSC conn use - fsm == 1 (0x1)
+DRLL Freeing subscriber connection with NULL subscriber
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
-DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
-DRLL Freeing subscriber connection with NULL subscriber
bssap_clear_sent == 1
- conn was released
llist_count(&net->subscr_conns) == 0
@@ -91,12 +96,9 @@
- Location Update request causes a GSUP LU request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
-DREF unknown: MSC conn use + fsm == 2 (0x5)
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
DMM LU/new-LAC: 1/23
@@ -120,8 +122,11 @@
DVLR GSUP tx: 04010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
-DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
-DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
+DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0)
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
@@ -181,21 +186,24 @@
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
+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 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)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
-- BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
-DRLL subscr MSISDN:46071: Freeing subscriber connection
+DRLL MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 2
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
@@ -210,12 +218,9 @@
- Location Update request causes a GSUP LU request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
-DREF unknown: MSC conn use + fsm == 2 (0x5)
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
DMM LU/new-LAC: 1/23
@@ -237,8 +242,11 @@
DVLR GSUP tx: 04010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
-DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
-DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
+DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0)
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
@@ -297,21 +305,24 @@
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
-DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
+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 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)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
-- BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
-DRLL subscr MSISDN:46071: Freeing subscriber connection
+DRLL MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 2
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
@@ -325,6 +336,7 @@
- subscriber detaches
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
new conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
@@ -333,10 +345,19 @@
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.
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
+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)
+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_two_lu: SUCCESS
@@ -348,12 +369,9 @@
- Location Update request with unknown TMSI sends ID Request for IMSI
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn
+DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
-DREF unknown: MSC conn use + fsm == 2 (0x5)
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Allocated
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Updated ID from LU
DMM LOCATION UPDATING REQUEST: MI(TMSI)=591536962 type=IMSI ATTACH
DMM LU/new-LAC: 1/23
@@ -370,8 +388,11 @@
DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A
- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051801
- DTAP matches expected message
-DMM TMSI:0x23422342: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
-DREF TMSI:0x23422342: MSC conn use - compl_l3 == 1 (0x4)
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
+DREF TMSI:0x23422342: MSC conn use - compl_l3 == 0 (0x0)
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
@@ -385,7 +406,7 @@
DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: SMS:0x01
- MS tells us the IMSI, causes a GSUP LU request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
-DREF TMSI:0x23422342: MSC conn use + dtap == 2 (0x6)
+DREF TMSI:0x23422342: MSC conn use + dtap == 1 (0x2)
DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
DMM IDENTITY RESPONSE: MI(IMSI)=901700000004620
DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
@@ -402,8 +423,9 @@
DVLR GSUP tx: 04010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
-DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
-DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
+DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0)
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
@@ -463,21 +485,24 @@
DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Freeing instance
DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
-DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
+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 MSISDN:46071: MSC conn use - release == 0 (0x0)
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
+DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(591536962)
DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
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.
-- BSSAP Clear --RAN_GERAN_A--> MS
-DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
-DRLL subscr MSISDN:46071: Freeing subscriber connection
+DRLL MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 2
DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Deallocated