enable osmo_fsm_term_safely(), apply logging changes
Start using osmo_fsm_term_safely(true), the recently added feature of
libosmocore's fsm.c. Deallocates in slightly changed order and with slightly
modified logging. Adjust test expectations.
Depends: I8eda67540a1cd444491beb7856b9fcd0a3143b18 (libosmocore)
Change-Id: I195a719d9ec1f6764ee5a361244f59f0144dc253
diff --git a/tests/msc_vlr/msc_vlr_test_ss.err b/tests/msc_vlr/msc_vlr_test_ss.err
index a801f9e..94b6cd5 100644
--- a/tests/msc_vlr/msc_vlr_test_ss.err
+++ b/tests/msc_vlr/msc_vlr_test_ss.err
@@ -59,8 +59,6 @@
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
-DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Freeing instance
-DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_INIT}: Allocated
@@ -72,10 +70,9 @@
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU))
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Freeing instance
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Deallocated
+DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU)
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_AUTH_CIPH}: state_chg to RAN_CONN_S_ACCEPTED
@@ -85,6 +82,7 @@
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
- BSSAP Clear --GERAN-A--> MS
+DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
DREF VLR subscr IMSI-901700000004620: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
@@ -100,15 +98,13 @@
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASING}: Received Event RAN_CONN_E_UNUSED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASING}: state_chg to RAN_CONN_S_RELEASED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU))
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Removing from parent RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Freeing instance
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Deallocated
+DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
DRLL IMSI-901700000004620:MSISDN-46071: Freeing RAN connection
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 1
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Freeing instance
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Deallocated
+DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Deallocated, including all deferred deallocations
llist_count(&net->ran_conns) == 0
---
- after a while, a new conn sends a CM Service Request
@@ -185,14 +181,12 @@
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASING}: Received Event RAN_CONN_E_UNUSED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASING}: state_chg to RAN_CONN_S_RELEASED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ))
DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Removing from parent RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ)
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Freeing instance
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Deallocated
+DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Deferring: will deallocate with RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ)
DRLL IMSI-901700000004620:MSISDN-46071: Freeing RAN connection
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 1
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASED}: Freeing instance
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASED}: Deallocated
+DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_RELEASED}: Deallocated, including all deferred deallocations
llist_count(&net->ran_conns) == 0
DREF freeing VLR subscr IMSI-901700000004620:MSISDN-46071
===== test_ss_ussd_mo_geran: SUCCESS
@@ -258,8 +252,6 @@
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
-DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Freeing instance
-DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_INIT}: Allocated
@@ -271,10 +263,9 @@
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU))
DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Freeing instance
-DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Deallocated
+DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU)
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_AUTH_CIPH}: state_chg to RAN_CONN_S_ACCEPTED
@@ -284,6 +275,7 @@
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
- BSSAP Clear --GERAN-A--> MS
+DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A-0:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
DREF VLR subscr IMSI-901700000004620: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
@@ -299,15 +291,13 @@
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASING}: Received Event RAN_CONN_E_UNUSED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASING}: state_chg to RAN_CONN_S_RELEASED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU))
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Removing from parent RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Freeing instance
-DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Deallocated
+DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU)
DRLL IMSI-901700000004620:MSISDN-46071: Freeing RAN connection
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 1
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Freeing instance
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Deallocated
+DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED}: Deallocated, including all deferred deallocations
llist_count(&net->ran_conns) == 0
---
- after a while, HLR initiates SS/USSD session
@@ -413,14 +403,12 @@
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASING}: Received Event RAN_CONN_E_UNUSED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASING}: state_chg to RAN_CONN_S_RELEASED
DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
+DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP))
DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Removing from parent RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP)
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Freeing instance
-DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Deallocated
+DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){PR_ARQ_S_DONE}: Deferring: will deallocate with RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP)
DRLL IMSI-901700000004620:MSISDN-46071: Freeing RAN connection
DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 1
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASED}: Freeing instance
-DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASED}: Deallocated
+DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_RELEASED}: Deallocated, including all deferred deallocations
llist_count(&net->ran_conns) == 0
DREF freeing VLR subscr IMSI-901700000004620:MSISDN-46071
===== test_ss_ussd_no_geran: SUCCESS