Gitiles
Code Review Sign In
gerrit.osmocom.org / osmo-msc / cbf2c93d118facc13600811563d22df5a944a416 / . / tests / msc_vlr / msc_vlr_test_ss.err
blob: 976b26395cd8fe159bf0078de8456f39aacdb04d [file] [log] [blame]
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]1DLMGCP MGCP client: using endpoint domain '@mgw'
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]2full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]3talloc_total_blocks(tall_bsc_ctx) == 17
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]4
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]5===== test_ss_ussd_mo_geran
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]6- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]7 MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]8 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]9DMSC msub_fsm{active}: Allocated
10DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
11DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
12DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
13DMSC dummy_msc_i{0}: Allocated
14DMSC dummy_msc_i{0}: is child of msub_fsm
15DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
16DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
17DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
18DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
19DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
20DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + mm_rx_loc_upd_req: now used by 2 (rx_from_ms,mm_rx_loc_upd_req)
21DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + lu: now used by 3 (rx_from_ms,mm_rx_loc_upd_req,lu)
22DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
23DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
24DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
25DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]26DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]27DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
28DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]29DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
30DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
31DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
32DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Oliver Smithcbf2c932019-05-06 13:09:55 +0200[diff] [blame^]33DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]34DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
35DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
36DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
37DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
38DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
39DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Allocated
40DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
41DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
42GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f02801020a0101
43DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
44DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - mm_rx_loc_upd_req: now used by 2 (rx_from_ms,lu)
45DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]46 lu_result_sent == 0
47- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]48<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101
49DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]50DVLR IMSI:901700000004620 has MSISDN:46071
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]51DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]52GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101
53DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]54<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
55 lu_result_sent == 0
56- HLR also sends GSUP _UPDATE_LOCATION_RESULT
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]57<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f00a0101
58DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
59DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
60DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
61DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
62DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
63DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
64DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
65DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
66DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Allocated
67DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
68DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
69DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
70DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
71- sending LU Accept for IMSI-901700000004620:MSISDN-46071:GERAN-A:LU
72DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + attached: now used by 3 (active-conn,vlr_gsup_rx,attached)
73DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
74DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
75DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A: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:LU))
76DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
77DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU)
78DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
79DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
80DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
81DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: - lu: now used by 0 (-)
82DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_UNUSED
83DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_RELEASING
84DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
85DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
86DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 5 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
87DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
88DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
89DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
90DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
91DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 3 (active-conn,vlr_gsup_rx,attached)
92DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
93DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (active-conn,attached)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]94<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
95- LU was successful, and the conn has already been closed
96 lu_result_sent == 1
97 bssap_clear_sent == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]98DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + perform_lu: now used by 3 (active-conn,attached,perform_lu)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]99 vsub != NULL == 1
100 strcmp(vsub->imsi, IMSI) == 0
Max33b6d0c2018-12-17 17:15:13 +0100[diff] [blame]101 LAC == 23
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]102DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - perform_lu: now used by 2 (active-conn,attached)
103DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
104DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
105DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
106DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
107DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
108DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
109DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
110DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
111DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
112DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
113DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
114DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
115DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
116DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
117DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
118DMSC msub_fsm{active}: state_chg to terminating
119DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
120DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
121DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Removing from parent msub_fsm
122DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
123DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
124DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 1 (attached)
125DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
126DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
127- msub gone
128 llist_count(&msub_list) == 0
129
130
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]131- after a while, a new conn sends a CM Service Request
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]132 MSC <--GERAN-A-- MS: GSM48_MT_MM_CM_SERV_REQ
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]133 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]134DMSC msub_fsm{active}: Allocated
135DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
136DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
137DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
138DMSC dummy_msc_i{0}: Allocated
139DMSC dummy_msc_i{0}: is child of msub_fsm
140DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
141DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
142DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_CM_SERV_REQ
143DMM msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: Rx CM SERVICE REQUEST cm_service_type=Supplementary-Service
144DREF msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: + cm_service_ss: now used by 2 (rx_from_ms,cm_service_ss)
145DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: Allocated
146DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: is child of msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ)
147DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
148DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]149DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + proc_arq_vlr_fn_init: now used by 2 (attached,proc_arq_vlr_fn_init)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]150DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + active-conn: now used by 3 (attached,proc_arq_vlr_fn_init,active-conn)
151DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
152DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
153DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
154DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
155DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
156DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
157DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
158DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
159DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
160DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: proc_arq_fsm_done(PASSED)
161DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
162DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Process Access Request result: PASSED
163DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: RAN encode: DTAP on GERAN-A
164- DTAP --GERAN-A--> MS: GSM48_MT_MM_CM_SERV_ACC: 0521
165DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
166DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
167DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
168DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - proc_arq_vlr_fn_init: now used by 2 (attached,active-conn)
169DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: - rx_from_ms: now used by 1 (cm_service_ss)
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]170 cm_service_result_sent == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]171msc_a_is_accepted() == true
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]172 MSC <--GERAN-A-- MS: GSM0480_MTYPE_REGISTER
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]173DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: + rx_from_ms: now used by 2 (cm_service_ss,rx_from_ms)
174DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: RAN decode: DTAP
175DRLL msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: Dispatching 04.08 message: NCSS GSM0480_MTYPE_REGISTER
176DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + NCSS: now used by 3 (attached,active-conn,NCSS)
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]177DSS trans(NCSS IMSI-901700000004620:MSISDN-46071 callref-0x20000001 tid-8) New transaction
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]178DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: + nc_ss: now used by 3 (cm_service_ss,rx_from_ms,nc_ss)
179DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_TRANSACTION_ACCEPTED
180DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_COMMUNICATING
181DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: - cm_service_ss: now used by 2 (rx_from_ms,nc_ss)
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]182DSS trans(NCSS IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ callref-0x20000001 tid-8) Received SS/USSD msg GSM0480_MTYPE_REGISTER
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]183GSUP --> HLR: OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200000013101013515a11302010102013b300b04010f0406aa510c061b010a0103
184DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: - rx_from_ms: now used by 1 (nc_ss)
185<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200000013101033527a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d0a0103
186DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + gsm0911_gsup_rx: now used by 4 (attached,active-conn,NCSS,gsm0911_gsup_rx)
187DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: RAN encode: DTAP on GERAN-A
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]188- DTAP --GERAN-A--> MS: GSM0480_MTYPE_RELEASE_COMPLETE: 8b2a1c27a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]189- DTAP matches expected message
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]190DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]191DSS trans(NCSS IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ callref-0x20000001 tid-8) Freeing transaction
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]192DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - NCSS: now used by 3 (attached,active-conn,gsm0911_gsup_rx)
193DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: - nc_ss: now used by 0 (-)
194DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: Received Event MSC_A_EV_UNUSED
195DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_COMMUNICATING}: state_chg to MSC_A_ST_RELEASING
196DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
197DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 4 (attached,active-conn,gsm0911_gsup_rx,msc_a_fsm_releasing_onenter)
198DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 5 (attached,active-conn,gsm0911_gsup_rx,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
199DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 4 (attached,active-conn,gsm0911_gsup_rx,msc_a_fsm_releasing_onenter)
200DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
201DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
202DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
203DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 3 (attached,active-conn,gsm0911_gsup_rx)
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]204<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns 0
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]205 dtap_tx_confirmed == 1
206 bssap_clear_sent == 1
207- all requests serviced, conn has been released
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]208DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
209DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
210DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
211DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
212DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
213DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
214DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
215DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
216DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
217DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
218DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: max total use count was 3
219DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
220DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
221DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
222DMSC msub_fsm{active}: state_chg to terminating
223DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
224DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
225DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Removing from parent msub_fsm
226DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
227DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
228DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 2 (attached,gsm0911_gsup_rx)
229DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
230DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
231- msub gone
232 llist_count(&msub_list) == 0
233DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]234===== test_ss_ussd_mo_geran: SUCCESS
235
236full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]237talloc_total_blocks(tall_bsc_ctx) == 17
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]238
239===== test_ss_ussd_no_geran
240- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]241 MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]242 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]243DMSC msub_fsm{active}: Allocated
244DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
245DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
246DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
247DMSC dummy_msc_i{0}: Allocated
248DMSC dummy_msc_i{0}: is child of msub_fsm
249DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
250DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
251DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
252DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
253DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
254DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + mm_rx_loc_upd_req: now used by 2 (rx_from_ms,mm_rx_loc_upd_req)
255DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + lu: now used by 3 (rx_from_ms,mm_rx_loc_upd_req,lu)
256DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
257DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
258DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
259DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]260DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]261DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
262DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]263DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
264DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
265DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
266DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Oliver Smithcbf2c932019-05-06 13:09:55 +0200[diff] [blame^]267DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]268DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
269DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
270DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
271DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
272DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
273DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Allocated
274DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
275DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
276GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f02801020a0101
277DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
278DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - mm_rx_loc_upd_req: now used by 2 (rx_from_ms,lu)
279DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]280 lu_result_sent == 0
281- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]282<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101
283DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]284DVLR IMSI:901700000004620 has MSISDN:46071
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]285DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]286GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101
287DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]288<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
289 lu_result_sent == 0
290- HLR also sends GSUP _UPDATE_LOCATION_RESULT
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]291<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f00a0101
292DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
293DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
294DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
295DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
296DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
297DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
298DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
299DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
300DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Allocated
301DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
302DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
303DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
304DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
305- sending LU Accept for IMSI-901700000004620:MSISDN-46071:GERAN-A:LU
306DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + attached: now used by 3 (active-conn,vlr_gsup_rx,attached)
307DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
308DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
309DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A: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:LU))
310DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
311DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU)
312DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
313DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
314DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
315DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: - lu: now used by 0 (-)
316DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_UNUSED
317DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_RELEASING
318DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
319DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
320DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 5 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
321DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
322DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
323DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
324DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
325DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 3 (active-conn,vlr_gsup_rx,attached)
326DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
327DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (active-conn,attached)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]328<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
329- LU was successful, and the conn has already been closed
330 lu_result_sent == 1
331 bssap_clear_sent == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]332DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + perform_lu: now used by 3 (active-conn,attached,perform_lu)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]333 vsub != NULL == 1
334 strcmp(vsub->imsi, IMSI) == 0
Max33b6d0c2018-12-17 17:15:13 +0100[diff] [blame]335 LAC == 23
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]336DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - perform_lu: now used by 2 (active-conn,attached)
337DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
338DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
339DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
340DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
341DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
342DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
343DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
344DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
345DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
346DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
347DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
348DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
349DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
350DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
351DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
352DMSC msub_fsm{active}: state_chg to terminating
353DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
354DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
355DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Removing from parent msub_fsm
356DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
357DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
358DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 1 (attached)
359DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
360DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
361- msub gone
362 llist_count(&msub_list) == 0
363
364
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]365- after a while, HLR initiates SS/USSD session
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]366DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + _test_ss_ussd_no: now used by 2 (attached,_test_ss_ussd_no)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]367 llist_count(&vsub->cs.requests) == 0
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]368<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200001013101013515a11302010102013b300b04010f0406aa510c061b010a0103
369DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + gsm0911_gsup_rx: now used by 3 (attached,_test_ss_ussd_no,gsm0911_gsup_rx)
370DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + NCSS: now used by 4 (attached,_test_ss_ussd_no,gsm0911_gsup_rx,NCSS)
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]371DSS trans(NCSS IMSI-901700000004620:MSISDN-46071 callref-0x20000101 tid-255) New transaction
372DSS trans(NCSS IMSI-901700000004620:MSISDN-46071 callref-0x20000101 tid-255) Establishing network-originated session
373DSS trans(NCSS IMSI-901700000004620:MSISDN-46071 callref-0x20000101 tid-0) Triggering Paging Request
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]374DPAG Paging: IMSI-901700000004620:MSISDN-46071 for GSM 09.11 SS/USSD: Starting paging
375 paging request (SIGNALLING_HIGH_PRIO) to IMSI-901700000004620:MSISDN-46071 on GERAN-A
376 strcmp(paging_expecting_imsi, vsub->imsi) == 0
377DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + Paging: now used by 5 (attached,_test_ss_ussd_no,gsm0911_gsup_rx,NCSS,Paging)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]378<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns -22
379 llist_count(&vsub->cs.requests) == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]380DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - _test_ss_ussd_no: now used by 4 (attached,gsm0911_gsup_rx,NCSS,Paging)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]381 paging_sent == 1
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]382- the subscriber and its pending request should remain
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]383DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + _test_ss_ussd_no: now used by 5 (attached,gsm0911_gsup_rx,NCSS,Paging,_test_ss_ussd_no)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]384 llist_count(&vsub->cs.requests) == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]385DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - _test_ss_ussd_no: now used by 4 (attached,gsm0911_gsup_rx,NCSS,Paging)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]386- MS replies with Paging Response, we deliver the NC/USSD
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]387 MSC <--GERAN-A-- MS: GSM48_MT_RR_PAG_RESP
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]388 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]389DMSC msub_fsm{active}: Allocated
390DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
391DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
392DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
393DMSC dummy_msc_i{0}: Allocated
394DMSC dummy_msc_i{0}: is child of msub_fsm
395DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
396DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
397DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: RR GSM48_MT_RR_PAG_RESP
398DRR msc_a(IMSI-901700000004620:GERAN-A:PAGING_RESP){MSC_A_ST_VALIDATE_L3}: Rx PAGING RESPONSE
399DREF msc_a(IMSI-901700000004620:GERAN-A:PAGING_RESP){MSC_A_ST_VALIDATE_L3}: + paging-response: now used by 2 (rx_from_ms,paging-response)
400DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: Allocated
401DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: is child of msc_a(IMSI-901700000004620:GERAN-A:PAGING_RESP)
402DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
403DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
404DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + proc_arq_vlr_fn_init: now used by 5 (attached,gsm0911_gsup_rx,NCSS,Paging,proc_arq_vlr_fn_init)
405DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + active-conn: now used by 6 (attached,gsm0911_gsup_rx,NCSS,Paging,proc_arq_vlr_fn_init,active-conn)
406DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
407DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
408DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
409DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
410DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
411DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
412DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
413DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
414DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
415DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: proc_arq_fsm_done(PASSED)
416DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
417DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_DONE}: Process Access Request result: PASSED
418DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
419DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
420DPAG Paging: IMSI-901700000004620:MSISDN-46071 for GSM 09.11 SS/USSD: Paging Response action (success)
421DPAG Paging: IMSI-901700000004620:MSISDN-46071 for GSM 09.11 SS/USSD: Removing Paging Request
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]422DSS msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: Paging succeeded
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]423DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: + nc_ss: now used by 3 (rx_from_ms,paging-response,nc_ss)
424DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: RAN encode: DTAP on GERAN-A
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]425- DTAP --GERAN-A--> MS: GSM0480_MTYPE_REGISTER: 0b3b1c15a11302010102013b300b04010f0406aa510c061b01
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]426- DTAP matches expected message
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]427DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
428DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - Paging: now used by 5 (attached,gsm0911_gsup_rx,NCSS,proc_arq_vlr_fn_init,active-conn)
429DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: - paging-response: now used by 2 (rx_from_ms,nc_ss)
430DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - proc_arq_vlr_fn_init: now used by 4 (attached,gsm0911_gsup_rx,NCSS,active-conn)
431DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: - rx_from_ms: now used by 1 (nc_ss)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]432 dtap_tx_confirmed == 1
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]433- MS responds to SS/USSD request
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]434 MSC <--GERAN-A-- MS: GSM0480_MTYPE_FACILITY
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]435DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: + rx_from_ms: now used by 2 (nc_ss,rx_from_ms)
436DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: RAN decode: DTAP
437DRLL msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: Dispatching 04.08 message: NCSS GSM0480_MTYPE_FACILITY
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]438DSS trans(NCSS IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP callref-0x20000101 tid-0) Received SS/USSD msg GSM0480_MTYPE_FACILITY
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]439GSUP --> HLR: OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200001013101023527a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d0a0103
440DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: - rx_from_ms: now used by 1 (nc_ss)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]441 dtap_tx_confirmed == 1
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]442- HLR terminates the session
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]443<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200001013101030a0103
444DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + gsm0911_gsup_rx: now used by 5 (attached,2*gsm0911_gsup_rx,NCSS,active-conn)
445DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: RAN encode: DTAP on GERAN-A
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]446- DTAP --GERAN-A--> MS: GSM0480_MTYPE_RELEASE_COMPLETE: 0b2a
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]447- DTAP matches expected message
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]448DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
Neels Hofmeyr979b0572019-05-09 15:24:49 +0200[diff] [blame]449DSS trans(NCSS IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP callref-0x20000101 tid-0) Freeing transaction
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]450DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - NCSS: now used by 4 (attached,2*gsm0911_gsup_rx,active-conn)
451DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: - nc_ss: now used by 0 (-)
452DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_UNUSED
453DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_RELEASING
454DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
455DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 5 (attached,2*gsm0911_gsup_rx,active-conn,msc_a_fsm_releasing_onenter)
456DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 6 (attached,2*gsm0911_gsup_rx,active-conn,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
457DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 5 (attached,2*gsm0911_gsup_rx,active-conn,msc_a_fsm_releasing_onenter)
458DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
459DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
460DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
461DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 4 (attached,2*gsm0911_gsup_rx,active-conn)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]462<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns 0
463 dtap_tx_confirmed == 1
464 bssap_clear_sent == 1
465- all requests serviced, conn has been released
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]466DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
467DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
468DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
469DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
470DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
471DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
472DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP))
473DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP)
474DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP)
475DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
476DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: max total use count was 3
477DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
478DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
479DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
480DMSC msub_fsm{active}: state_chg to terminating
481DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP))
482DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP))
483DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Removing from parent msub_fsm
484DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP)
485DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
486DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 3 (attached,2*gsm0911_gsup_rx)
487DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP)
488DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
489- msub gone
490 llist_count(&msub_list) == 0
491DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6)
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame]492===== test_ss_ussd_no_geran: SUCCESS
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]493
494full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]495talloc_total_blocks(tall_bsc_ctx) == 17
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]496
497full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]498talloc_total_blocks(tall_bsc_ctx) == 17
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]499