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