blob: 5d5e1ec6e470e4692f13c1e6da5926776b209e9b [file] [log] [blame]
Neels Hofmeyr08b38282018-03-30 23:04:04 +02001full talloc report on 'msgb' (total 0 bytes in 1 blocks)
2talloc_total_blocks(tall_bsc_ctx) == 12
3
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +01004===== test_early_stage
Neels Hofmeyr6a29d322017-01-25 15:04:16 +01005- NULL conn
6msc_subscr_conn_is_accepted() == false
7- freshly allocated conn
8msc_subscr_conn_is_accepted() == false
9- conn_fsm present, in state NEW
Neels Hofmeyr6166f292017-11-22 14:33:12 +010010DREF unknown: MSC conn use + fsm == 1 (0x4)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020011DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Allocated
12DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
13DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010014msc_subscr_conn_is_accepted() == false
15 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +010016DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
17DRLL subscr unknown: Message not permitted for initial conn: GSM48_MT_CC_SETUP
18DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
19DRLL subscr unknown: Message not permitted for initial conn: unknown 0x33
20DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
21DRLL subscr unknown: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +010022DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
23DRLL subscr unknown: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010024- fake: acceptance
25DREF VLR subscr unknown usage increases to: 1
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020026DMM Subscr_Conn(test){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010027 llist_count(&net->subscr_conns) == 1
28msc_subscr_conn_is_accepted() == true
29- CLOSE event marks conn_fsm as released and frees the conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020030DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_CLOSE
31DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
32DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010033DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +020034- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +010035DREF unknown: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010036DRLL subscr unknown: Freeing subscriber connection
37DREF VLR subscr unknown usage decreases to: 0
38DREF freeing VLR subscr unknown
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020039DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Freeing instance
40DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Deallocated
Philipp Maierfbf66102017-04-09 12:32:51 +020041 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010042 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010043===== test_early_stage: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010044
45full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +020046talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010047
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010048===== test_cm_service_without_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010049- CM Service Request without a prior Location Updating
Neels Hofmeyr78ada642017-03-10 02:15:20 +010050 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010051 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +010052DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +010053DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010054DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
Neels Hofmeyr6166f292017-11-22 14:33:12 +010055DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020056DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
57DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
58DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +020059DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from CM_SERVICE_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010060DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
61DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
62DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
63DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
64DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_UNIDENT_SUBSCR)
65DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
66DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_UNIDENT_SUBSCR
67- sending CM Service Reject for unknown, result VLR_PR_ARQ_RES_UNIDENT_SUBSCR
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020068DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020069DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED
70DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010071DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
72DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
73DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
74DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
75DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +020076- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +010077DREF unknown: MSC conn use - fsm == 1 (0x1)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020078DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
79DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +010080DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010081DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +020082 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010083- conn was released
84 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010085===== test_cm_service_without_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010086
87full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +020088talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010089
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010090===== test_two_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010091- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +010092 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010093 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +010094DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +010095DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +010096DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020097DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
98DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
99DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200100DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100101DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100102DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100103DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
104DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
105DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
106DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
107DREF VLR subscr unknown usage increases to: 1
108DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
109DVLR New subscr, IMSI: 901700000004620
110DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200111DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100112DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
113DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
114DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
115DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
116DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
117DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
118DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
119DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
120DVLR GSUP tx: 04010809710000004026f0
121GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
122DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100123DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100124DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100125 lu_result_sent == 0
126- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
127<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
128DVLR GSUP rx 17: 10010809710000004026f00804036470f1
129DREF VLR subscr IMSI:901700000004620 usage increases to: 2
130DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100131DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100132DVLR GSUP tx: 12010809710000004026f0
133GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
134DREF VLR subscr MSISDN:46071 usage decreases to: 1
135<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
136 lu_result_sent == 0
137- having received subscriber data does not mean acceptance
138msc_subscr_conn_is_accepted() == false
139 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100140DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
141DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
142DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
143DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
144DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
145DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100146DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
147DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100148 lu_result_sent == 0
149- HLR also sends GSUP _UPDATE_LOCATION_RESULT
150<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
151DVLR GSUP rx 11: 06010809710000004026f0
152DREF VLR subscr MSISDN:46071 usage increases to: 2
153DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
154DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
155DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
156DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
157DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
158DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
159DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
160DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
161DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
162DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
163DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
164DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
165DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
166DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
167DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
168DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
169DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
170DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
171DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
172DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
173DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
174DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
175- sending LU Accept for MSISDN:46071
176DREF VLR subscr MSISDN:46071 usage increases to: 3
177DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
178DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
179DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
180DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
181DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
182DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
183DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200184DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200185DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100186DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
187DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200188DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
189DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100190DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
191DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
192DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
193DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
194DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
195DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200196- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100197DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100198DRLL subscr MSISDN:46071: Freeing subscriber connection
199DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200200DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
201DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100202DREF VLR subscr MSISDN:46071 usage decreases to: 1
203<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200204 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100205- LU was successful, and the conn has already been closed
206 lu_result_sent == 1
207 llist_count(&net->subscr_conns) == 0
208---
209- verify that the MS can send another LU request
210- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100211 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100212 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100213DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100214DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100215DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200216DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
217DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
218DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200219DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100220DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100221DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100222DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
223DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
224DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
225DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
226DREF VLR subscr MSISDN:46071 usage increases to: 2
227DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200228DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100229DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
230DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
231DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
232DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
233DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
234DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
235DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
236DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
237DVLR GSUP tx: 04010809710000004026f0
238GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
239DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100240DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100241DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100242 lu_result_sent == 0
243- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
244<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
245DVLR GSUP rx 17: 10010809710000004026f00804036470f1
246DREF VLR subscr MSISDN:46071 usage increases to: 3
247DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100248DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=3)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100249DVLR GSUP tx: 12010809710000004026f0
250GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
251DREF VLR subscr MSISDN:46071 usage decreases to: 2
252<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
253 lu_result_sent == 0
254- having received subscriber data does not mean acceptance
255msc_subscr_conn_is_accepted() == false
256 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100257DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
258DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
259DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
260DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
261DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
262DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100263DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
264DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100265 lu_result_sent == 0
266- HLR also sends GSUP _UPDATE_LOCATION_RESULT
267<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
268DVLR GSUP rx 11: 06010809710000004026f0
269DREF VLR subscr MSISDN:46071 usage increases to: 3
270DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
271DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
272DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
273DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
274DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
275DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
276DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
277DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
278DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
279DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
280DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
281DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
282DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
283DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
284DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
285DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
286DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
287DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
288DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
289DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
290DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
291DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
292- sending LU Accept for MSISDN:46071
293DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
294DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
295DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
296DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
297DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
298DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
299DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200300DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200301DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100302DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
303DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200304DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
305DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100306DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
307DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
308DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
309DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
310DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
311DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200312- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100313DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100314DRLL subscr MSISDN:46071: Freeing subscriber connection
315DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200316DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
317DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100318DREF VLR subscr MSISDN:46071 usage decreases to: 1
319<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200320 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100321- LU was successful, and the conn has already been closed
322 lu_result_sent == 1
323 llist_count(&net->subscr_conns) == 0
324---
325- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100326 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100327 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100328DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100329DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100330DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
331DREF VLR subscr MSISDN:46071 usage increases to: 2
332DMM IMSI DETACH for MSISDN:46071
333DREF VLR subscr MSISDN:46071 usage decreases to: 1
334DREF VLR subscr MSISDN:46071 usage decreases to: 0
335DREF freeing VLR subscr MSISDN:46071
336DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200337- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100338DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100339DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200340 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100341 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100342===== test_two_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100343
344full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200345talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100346
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100347===== test_lu_unknown_tmsi
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100348- Location Update request with unknown TMSI sends ID Request for IMSI
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100349 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100350 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100351DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100352DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100353DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200354DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Allocated
355DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
356DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200357DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100358DMM LOCATION UPDATING REQUEST: MI(TMSI)=591536962 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100359DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100360DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Allocated
361DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: is child of Subscr_Conn(591536962)
362DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
363DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
364DREF VLR subscr unknown usage increases to: 1
365DVLR New subscr, TMSI: 0x23422342
366DREF VLR subscr TMSI:0x23422342 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200367DREF VLR subscr TMSI:0x23422342 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100368DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
369DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200370DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100371- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051801
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100372- DTAP matches expected message
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100373DMM TMSI:0x23422342: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100374DREF TMSI:0x23422342: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100375 lu_result_sent == 0
376msc_subscr_conn_is_accepted() == false
377 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100378DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
379DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
380DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
381DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: unknown 0x33
382DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
383DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100384DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
385DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100386- MS tells us the IMSI, causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100387 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100388DREF TMSI:0x23422342: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100389DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100390DMM IDENTITY RESPONSE: MI(IMSI)=901700000004620
391DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
392DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
393DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
394DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
395DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
396DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
397DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
398DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
399DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Allocated
400DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
401DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
402DVLR GSUP tx: 04010809710000004026f0
403GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
404DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100405DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100406DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100407 lu_result_sent == 0
408- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
409<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
410DVLR GSUP rx 17: 10010809710000004026f00804036470f1
411DREF VLR subscr IMSI:901700000004620 usage increases to: 2
412DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100413DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100414DVLR GSUP tx: 12010809710000004026f0
415GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
416DREF VLR subscr MSISDN:46071 usage decreases to: 1
417<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
418 lu_result_sent == 0
419- having received subscriber data does not mean acceptance
420msc_subscr_conn_is_accepted() == false
421 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100422DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
423DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
424DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
425DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
426DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
427DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100428DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
429DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100430 lu_result_sent == 0
431- HLR also sends GSUP _UPDATE_LOCATION_RESULT
432<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
433DVLR GSUP rx 11: 06010809710000004026f0
434DREF VLR subscr MSISDN:46071 usage increases to: 2
435DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
436DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
437DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
438DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
439DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
440DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Freeing instance
441DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Deallocated
442DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
443DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
444DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Allocated
445DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
446DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
447DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
448DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Allocated
449DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(591536962)
450DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
451DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
452DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
453DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(591536962)
454DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Freeing instance
455DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Deallocated
456DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
457- sending LU Accept for MSISDN:46071
458DREF VLR subscr MSISDN:46071 usage increases to: 3
459DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
460DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
461DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
462DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
463DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Freeing instance
464DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Deallocated
465DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200466DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200467DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100468DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
469DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200470DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
471DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100472DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
473DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(591536962)
474DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
475DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Freeing instance
476DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Deallocated
477DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200478- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100479DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100480DRLL subscr MSISDN:46071: Freeing subscriber connection
481DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200482DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance
483DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100484DREF VLR subscr MSISDN:46071 usage decreases to: 1
485<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200486 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100487- LU was successful, and the conn has already been closed
488 lu_result_sent == 1
489 llist_count(&net->subscr_conns) == 0
490DREF freeing VLR subscr MSISDN:46071
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100491===== test_lu_unknown_tmsi: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100492
493full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200494talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100495
496full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200497talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100498