Gitiles
Code Review Sign In
gerrit.osmocom.org / osmo-msc / f2f83b07f36d9676e02f90320d69b3f63f55d8e8 / . / tests / msc_vlr / msc_vlr_test_ss.err
blob: 338b5aa071e5f3b14e36f512a48069ebe15862cc [file] [log] [blame]
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]1full talloc report on 'msgb' (total 0 bytes in 1 blocks)
2talloc_total_blocks(tall_bsc_ctx) == 12
3
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame^]4===== test_ss_ussd_mo_geran
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]5- Location Update request causes a GSUP LU request to HLR
6 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
7 new conn
8DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
9DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
10DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
11DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
12DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
13DMM LU/new-LAC: 1/23
14DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
15DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
16DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
17DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
18DREF VLR subscr unknown usage increases to: 1
19DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
20DVLR New subscr, IMSI: 901700000004620
21DREF VLR subscr IMSI:901700000004620 usage increases to: 2
22DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
23DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
24DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
25DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
26DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
27DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
28DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
29DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
30DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
31DVLR GSUP tx: 04010809710000004026f0
32GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
33DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
34DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
35DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
36DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0: )
37DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
38DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
39 lu_result_sent == 0
40- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
41<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
42DVLR GSUP rx 17: 10010809710000004026f00804036470f1
43DREF VLR subscr IMSI:901700000004620 usage increases to: 2
44DVLR IMSI:901700000004620 has MSISDN:46071
45DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
46DVLR GSUP tx: 12010809710000004026f0
47GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
48DREF VLR subscr MSISDN:46071 usage decreases to: 1
49<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
50 lu_result_sent == 0
51- HLR also sends GSUP _UPDATE_LOCATION_RESULT
52<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
53DVLR GSUP rx 11: 06010809710000004026f0
54DREF VLR subscr MSISDN:46071 usage increases to: 2
55DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
56DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
57DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
58DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
59DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
60DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
61DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
62DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
63DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
64DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
65DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
66DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
67DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
68DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
69DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
70DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
71DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
72DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
73DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
74DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
75DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
76DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
77- sending LU Accept for MSISDN:46071
78DREF VLR subscr MSISDN:46071 usage increases to: 3
79DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
80DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
81DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
82DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
83DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
84DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
85DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
86DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
87DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
88DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
89DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
90DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
91DREF VLR subscr MSISDN:46071 usage increases to: 4
92DREF VLR subscr MSISDN:46071 usage decreases to: 3
93- BSSAP Clear --RAN_GERAN_A--> MS
94DREF VLR subscr MSISDN:46071 usage decreases to: 2
95<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
96- LU was successful, and the conn has already been closed
97 lu_result_sent == 1
98 bssap_clear_sent == 1
99DREF VLR subscr MSISDN:46071 usage increases to: 3
100 vsub != NULL == 1
101 strcmp(vsub->imsi, IMSI) == 0
102 vsub->lac == 23
103DREF VLR subscr MSISDN:46071 usage decreases to: 2
104- BSS sends BSSMAP Clear Complete
105DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
106DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
107DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
108DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
109DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
110DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
111DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
112DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
113DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
114DRLL MSISDN:46071: Freeing subscriber connection
115DREF VLR subscr MSISDN:46071 usage decreases to: 1
116DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
117DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
118 llist_count(&net->subscr_conns) == 0
119---
120- after a while, a new conn sends a CM Service Request
121 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
122 new conn
123DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
124DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
125DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
126DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
127DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
128DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Allocated
129DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(CM_SERVICE_REQ:901700000004620)
130DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
131DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
132DREF VLR subscr MSISDN:46071 usage increases to: 2
133DREF VLR subscr MSISDN:46071 usage increases to: 3
134DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
135DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
136DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
137DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
138DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
139DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
140DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
141DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(PASSED)
142DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
143DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
144- sending CM Service Accept for MSISDN:46071
145DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
146DREF MSISDN:46071: MSC conn use + cm_service == 2 (0x9: compl_l3,cm_service)
147DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
148DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: still awaiting first request after a CM Service Request
149DREF VLR subscr MSISDN:46071 usage decreases to: 2
150DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
151DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Event SUBSCR_CONN_E_COMPLETE_LAYER_3 not permitted
152DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x8: cm_service)
153 cm_service_result_sent == 1
154msc_subscr_conn_is_accepted() == true
155 MSC <--RAN_GERAN_A-- MS: GSM0480_MTYPE_REGISTER
156DREF MSISDN:46071: MSC conn use + dtap == 2 (0xa: dtap,cm_service)
157DRLL Dispatching 04.08 message GSM0480_MTYPE_REGISTER (0xb:0x3b)
158DMM Received SS/USSD data (trans_id=8, msg_type=GSM0480_MTYPE_REGISTER)
159DMM -> (new transaction)
160DCC (ti 08 sub MSISDN:46071 callref 20000001) New transaction
161DREF VLR subscr MSISDN:46071 usage increases to: 3
162DREF MSISDN:46071: MSC conn use + trans_nc_ss == 3 (0x4a: dtap,cm_service,trans_nc_ss)
163DMM MSISDN:46071: rx msg GSM0480_MTYPE_REGISTER: received_cm_service_request changes to false
164DREF MSISDN:46071: MSC conn use - cm_service == 2 (0x42: dtap,trans_nc_ss)
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]165GSUP --> HLR: OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200000013101013515a11302010102013b300b04010f0406aa510c061b01
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]166DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
167DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]168DREF MSISDN:46071: MSC conn use - dtap == 1 (0x40: trans_nc_ss)
169<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200000013101033527a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
170DVLR GSUP rx 61: 20010809710000004026f03004200000013101033527a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
171DREF VLR subscr MSISDN:46071 usage increases to: 4
172DMSC Routed to GSM 09.11 SS/USSD handler
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]173DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A
174- DTAP --RAN_GERAN_A--> MS: GSM0480_MTYPE_RELEASE_COMPLETE: 8b2a1c27a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
175- DTAP matches expected message
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]176DREF VLR subscr MSISDN:46071 usage decreases to: 3
177DREF MSISDN:46071: MSC conn use - trans_nc_ss == 0 (0x0: )
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]178DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED
179DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING
180DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]181DREF VLR subscr MSISDN:46071 usage increases to: 4
182DREF VLR subscr MSISDN:46071 usage decreases to: 3
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]183- BSSAP Clear --RAN_GERAN_A--> MS
Vadim Yanitskiy8a6ef552018-06-12 08:21:20 +0700[diff] [blame]184DREF VLR subscr MSISDN:46071 usage decreases to: 2
185<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns 0
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]186 dtap_tx_confirmed == 1
187 bssap_clear_sent == 1
188- all requests serviced, conn has been released
189- BSS sends BSSMAP Clear Complete
190DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
191DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
192DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
193DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
194DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
195DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000004620)
196DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Freeing instance
197DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Deallocated
198DRLL MSISDN:46071: Freeing subscriber connection
199DREF VLR subscr MSISDN:46071 usage decreases to: 1
200DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
201DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
202 llist_count(&net->subscr_conns) == 0
203DREF freeing VLR subscr MSISDN:46071
Vadim Yanitskiyf2f83b02018-06-17 21:09:28 +0700[diff] [blame^]204===== test_ss_ussd_mo_geran: SUCCESS
205
206full talloc report on 'msgb' (total 0 bytes in 1 blocks)
207talloc_total_blocks(tall_bsc_ctx) == 12
208
209===== test_ss_ussd_no_geran
210- Location Update request causes a GSUP LU request to HLR
211 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
212 new conn
213DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
214DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
215DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
216DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
217DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
218DMM LU/new-LAC: 1/23
219DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
220DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
221DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
222DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
223DREF VLR subscr unknown usage increases to: 1
224DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
225DVLR New subscr, IMSI: 901700000004620
226DREF VLR subscr IMSI:901700000004620 usage increases to: 2
227DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
228DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
229DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
230DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
231DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
232DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
233DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
234DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
235DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
236DVLR GSUP tx: 04010809710000004026f0
237GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
238DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
239DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
240DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
241DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0: )
242DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
243DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
244 lu_result_sent == 0
245- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
246<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
247DVLR GSUP rx 17: 10010809710000004026f00804036470f1
248DREF VLR subscr IMSI:901700000004620 usage increases to: 2
249DVLR IMSI:901700000004620 has MSISDN:46071
250DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
251DVLR GSUP tx: 12010809710000004026f0
252GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
253DREF VLR subscr MSISDN:46071 usage decreases to: 1
254<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
255 lu_result_sent == 0
256- HLR also sends GSUP _UPDATE_LOCATION_RESULT
257<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
258DVLR GSUP rx 11: 06010809710000004026f0
259DREF VLR subscr MSISDN:46071 usage increases to: 2
260DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
261DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
262DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
263DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
264DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
265DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
266DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
267DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
268DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
269DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
270DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
271DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
272DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
273DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
274DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
275DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
276DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
277DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
278DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
279DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
280DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
281DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
282- sending LU Accept for MSISDN:46071
283DREF VLR subscr MSISDN:46071 usage increases to: 3
284DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
285DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
286DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
287DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
288DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
289DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
290DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
291DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
292DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
293DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
294DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
295DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
296DREF VLR subscr MSISDN:46071 usage increases to: 4
297DREF VLR subscr MSISDN:46071 usage decreases to: 3
298- BSSAP Clear --RAN_GERAN_A--> MS
299DREF VLR subscr MSISDN:46071 usage decreases to: 2
300<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
301- LU was successful, and the conn has already been closed
302 lu_result_sent == 1
303 bssap_clear_sent == 1
304DREF VLR subscr MSISDN:46071 usage increases to: 3
305 vsub != NULL == 1
306 strcmp(vsub->imsi, IMSI) == 0
307 vsub->lac == 23
308DREF VLR subscr MSISDN:46071 usage decreases to: 2
309- BSS sends BSSMAP Clear Complete
310DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
311DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
312DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
313DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
314DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
315DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
316DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
317DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
318DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
319DRLL MSISDN:46071: Freeing subscriber connection
320DREF VLR subscr MSISDN:46071 usage decreases to: 1
321DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
322DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
323 llist_count(&net->subscr_conns) == 0
324---
325- after a while, HLR initiates SS/USSD session
326DREF VLR subscr MSISDN:46071 usage increases to: 2
327 llist_count(&vsub->cs.requests) == 0
328<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200001013101013515a11302010102013b300b04010f0406aa510c061b01
329DVLR GSUP rx 43: 20010809710000004026f03004200001013101013515a11302010102013b300b04010f0406aa510c061b01
330DREF VLR subscr MSISDN:46071 usage increases to: 3
331DMSC Routed to GSM 09.11 SS/USSD handler
332DMM Establishing network-originated session
333DCC (ti ff sub MSISDN:46071 callref 20000101) New transaction
334DREF VLR subscr MSISDN:46071 usage increases to: 4
335DMM Triggering Paging Request
336DMM Subscriber MSISDN:46071 not paged yet, start paging.
337 RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
338 strcmp(paging_expecting_imsi, imsi) == 0
339DREF VLR subscr MSISDN:46071 usage increases to: 5
340DREF VLR subscr MSISDN:46071 usage decreases to: 4
341<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns -22
342 llist_count(&vsub->cs.requests) == 1
343DREF VLR subscr MSISDN:46071 usage decreases to: 3
344 paging_sent == 1
345 paging_stopped == 0
346- the subscriber and its pending request should remain
347DREF VLR subscr MSISDN:46071 usage increases to: 4
348 llist_count(&vsub->cs.requests) == 1
349DREF VLR subscr MSISDN:46071 usage decreases to: 3
350- MS replies with Paging Response, we deliver the NC/USSD
351 MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
352 new conn
353DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
354DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
355DRLL Dispatching 04.08 message GSM48_MT_RR_PAG_RESP (0x6:0x27)
356DRR PAGING RESPONSE: MI(IMSI)=901700000004620
357DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
358DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Allocated
359DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
360DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
361DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
362DREF VLR subscr MSISDN:46071 usage increases to: 4
363DREF VLR subscr MSISDN:46071 usage increases to: 5
364DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
365DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
366DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
367DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
368DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
369DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
370DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
371DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(PASSED)
372DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
373DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
374DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
375DPAG Paging success for MSISDN:46071 (event=0)
376DPAG Calling paging cbfn.
377DMM Paging subscr 46071 succeeded!
378DREF MSISDN:46071: MSC conn use + trans_nc_ss == 2 (0x41: compl_l3,trans_nc_ss)
379DMSC msc_tx 25 bytes to MSISDN:46071 via RAN_GERAN_A
380- DTAP --RAN_GERAN_A--> MS: GSM0480_MTYPE_REGISTER: 0b3b1c15a11302010102013b300b04010f0406aa510c061b01
381- DTAP matches expected message
382DREF VLR subscr MSISDN:46071 usage decreases to: 4
383DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
384DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: connection still has active transaction: NCSS
385DREF VLR subscr MSISDN:46071 usage decreases to: 3
386DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
387DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Event SUBSCR_CONN_E_COMPLETE_LAYER_3 not permitted
388DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x40: trans_nc_ss)
389 dtap_tx_confirmed == 1
390 paging_stopped == 1
391- MS responds to SS/USSD request
392 MSC <--RAN_GERAN_A-- MS: GSM0480_MTYPE_FACILITY
393DREF MSISDN:46071: MSC conn use + dtap == 2 (0x42: dtap,trans_nc_ss)
394DRLL Dispatching 04.08 message GSM0480_MTYPE_FACILITY (0xb:0x3a)
395DMM Received SS/USSD data (trans_id=0, msg_type=GSM0480_MTYPE_FACILITY)
396GSUP --> HLR: OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f03004200001013101023527a225020101302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
397DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
398DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
399DREF MSISDN:46071: MSC conn use - dtap == 1 (0x40: trans_nc_ss)
400 dtap_tx_confirmed == 1
401 paging_stopped == 1
402- HLR terminates the session
403<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: 20010809710000004026f0300420000101310103
404DVLR GSUP rx 20: 20010809710000004026f0300420000101310103
405DREF VLR subscr MSISDN:46071 usage increases to: 4
406DMSC Routed to GSM 09.11 SS/USSD handler
407DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A
408- DTAP --RAN_GERAN_A--> MS: GSM0480_MTYPE_RELEASE_COMPLETE: 0b2a
409- DTAP matches expected message
410DREF VLR subscr MSISDN:46071 usage decreases to: 3
411DREF MSISDN:46071: MSC conn use - trans_nc_ss == 0 (0x0: )
412DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED
413DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING
414DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
415DREF VLR subscr MSISDN:46071 usage increases to: 4
416DREF VLR subscr MSISDN:46071 usage decreases to: 3
417- BSSAP Clear --RAN_GERAN_A--> MS
418DREF VLR subscr MSISDN:46071 usage decreases to: 2
419<-- GSUP rx OSMO_GSUP_MSGT_PROC_SS_REQUEST: vlr_gsupc_read_cb() returns 0
420 dtap_tx_confirmed == 1
421 bssap_clear_sent == 1
422- all requests serviced, conn has been released
423- BSS sends BSSMAP Clear Complete
424DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
425DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
426DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
427DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
428DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
429DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(PAGING_RESP:901700000004620)
430DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Freeing instance
431DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Deallocated
432DRLL MSISDN:46071: Freeing subscriber connection
433DREF VLR subscr MSISDN:46071 usage decreases to: 1
434DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
435DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
436 llist_count(&net->subscr_conns) == 0
437DREF freeing VLR subscr MSISDN:46071
438===== test_ss_ussd_no_geran: SUCCESS
Vadim Yanitskiy27605852018-06-15 23:57:30 +0700[diff] [blame]439
440full talloc report on 'msgb' (total 0 bytes in 1 blocks)
441talloc_total_blocks(tall_bsc_ctx) == 12
442
443full talloc report on 'msgb' (total 0 bytes in 1 blocks)
444talloc_total_blocks(tall_bsc_ctx) == 12
445