Gitiles
Code Review Sign In
gerrit.osmocom.org / osmo-gbproxy / de635e7908f11b0fa85a8252ceb9c3b5a217575d / . / tests / msc_vlr / msc_vlr_test_rest.err
blob: 6122040c9aaf9f50fc256e1ba76b0a63c7079157 [file] [log] [blame]
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]1===== test_early_stage
2- NULL conn
3msc_subscr_conn_is_accepted() == false
4- freshly allocated conn
5msc_subscr_conn_is_accepted() == false
6- conn_fsm present, in state NEW
7DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]8DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Allocated
9DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
10DMM Subscr_Conn(test){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]11msc_subscr_conn_is_accepted() == false
12 requests shall be thwarted
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]13DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
14DRLL subscr unknown: Message not permitted for initial conn: GSM48_MT_CC_SETUP
15DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
16DRLL subscr unknown: Message not permitted for initial conn: unknown 0x33
17DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
18DRLL subscr unknown: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
19DRLL Dispatching 04.08 message GSM48_PDISC_SMS:0x01 (0x9:0x1)
20DRLL subscr unknown: Message not permitted for initial conn: GSM48_PDISC_SMS:0x01
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]21- fake: acceptance
22DREF VLR subscr unknown usage increases to: 1
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]23DMM Subscr_Conn(test){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]24 llist_count(&net->subscr_conns) == 1
25msc_subscr_conn_is_accepted() == true
26- CLOSE event marks conn_fsm as released and frees the conn
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]27DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_CLOSE
28DMM Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
29DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]30DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
31DMM unknown: Unknown RAN type, cannot tx release/clear
32DREF unknown: MSC conn use - 1 == 0
33DRLL subscr unknown: Freeing subscriber connection
34DREF VLR subscr unknown usage decreases to: 0
35DREF freeing VLR subscr unknown
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]36DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Freeing instance
37DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]38 llist_count(&net->subscr_conns) == 0
39===== test_early_stage: SUCCESS
40
41full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]42talloc_total_blocks(tall_bsc_ctx) == 9
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]43
44===== test_cm_service_without_lu
45- CM Service Request without a prior Location Updating
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]46 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]47 new conn
48DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]49DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]50DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
51DREF unknown: MSC conn use + 1 == 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]52DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
53DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
54DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]55DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
56DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
57DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
58DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
59DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_UNIDENT_SUBSCR)
60DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
61DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_UNIDENT_SUBSCR
62- sending CM Service Reject for unknown, result VLR_PR_ARQ_RES_UNIDENT_SUBSCR
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]63DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
64DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_CM_SERVICE_REQ
65DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 2
66DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED
67DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]68DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
69DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
70DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
71DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
72DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
73DREF unknown: MSC conn use - 1 == 1
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]74DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
75DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
76DREF unknown: MSC conn use - 1 == 0
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]77DRLL Freeing subscriber connection with NULL subscriber
78- conn was released
79 llist_count(&net->subscr_conns) == 0
80===== test_cm_service_without_lu: SUCCESS
81
82full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]83talloc_total_blocks(tall_bsc_ctx) == 9
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]84
85===== test_two_lu
86- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]87 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]88 new conn
89DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]90DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]91DREF unknown: MSC conn use + 1 == 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]92DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
93DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
94DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]95DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
96DMM LU/new-LAC: 1/0
97DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
98DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
99DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
100DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
101DREF VLR subscr unknown usage increases to: 1
102DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
103DVLR New subscr, IMSI: 901700000004620
104DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr0e255582017-07-18 15:39:27 +0200[diff] [blame]105DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]106DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
107DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
108DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
109DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
110DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
111DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
112DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
113DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
114DVLR GSUP tx: 04010809710000004026f0
115GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
116DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]117DMM IMSI:901700000004620: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]118DREF IMSI:901700000004620: MSC conn use - 1 == 1
119 lu_result_sent == 0
120- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
121<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
122DVLR GSUP rx 17: 10010809710000004026f00804036470f1
123DREF VLR subscr IMSI:901700000004620 usage increases to: 2
124DVLR IMSI:901700000004620 has MSISDN:46071
125DVLR GSUP tx: 12010809710000004026f0
126GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
127DREF VLR subscr MSISDN:46071 usage decreases to: 1
128<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
129 lu_result_sent == 0
130- having received subscriber data does not mean acceptance
131msc_subscr_conn_is_accepted() == false
132 requests shall be thwarted
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]133DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
134DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
135DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
136DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
137DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
138DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
139DRLL Dispatching 04.08 message GSM48_PDISC_SMS:0x01 (0x9:0x1)
140DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_PDISC_SMS:0x01
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]141 lu_result_sent == 0
142- HLR also sends GSUP _UPDATE_LOCATION_RESULT
143<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
144DVLR GSUP rx 11: 06010809710000004026f0
145DREF VLR subscr MSISDN:46071 usage increases to: 2
146DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
147DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
148DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
149DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
150DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
151DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
152DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
153DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
154DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
155DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
156DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
157DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
158DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
159DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
160DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
161DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
162DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
163DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
164DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
165DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
166DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
167DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
168- sending LU Accept for MSISDN:46071
169DREF VLR subscr MSISDN:46071 usage increases to: 3
170DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
171DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
172DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
173DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
174DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
175DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
176DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]177DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
178DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
179DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
180DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
181DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
182DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
183DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]184DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
185DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
186DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
187DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
188DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
189DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
190DREF MSISDN:46071: MSC conn use - 1 == 0
191DRLL subscr MSISDN:46071: Freeing subscriber connection
192DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]193DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
194DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]195DREF VLR subscr MSISDN:46071 usage decreases to: 1
196<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
197- LU was successful, and the conn has already been closed
198 lu_result_sent == 1
199 llist_count(&net->subscr_conns) == 0
200---
201- verify that the MS can send another LU request
202- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]203 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]204 new conn
205DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]206DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]207DREF unknown: MSC conn use + 1 == 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]208DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
209DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
210DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]211DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
212DMM LU/new-LAC: 1/0
213DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
214DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
215DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
216DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
217DREF VLR subscr MSISDN:46071 usage increases to: 2
218DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr0e255582017-07-18 15:39:27 +0200[diff] [blame]219DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]220DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
221DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
222DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
223DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
224DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
225DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
226DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
227DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
228DVLR GSUP tx: 04010809710000004026f0
229GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
230DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]231DMM MSISDN:46071: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]232DREF MSISDN:46071: MSC conn use - 1 == 1
233 lu_result_sent == 0
234- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
235<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
236DVLR GSUP rx 17: 10010809710000004026f00804036470f1
237DREF VLR subscr MSISDN:46071 usage increases to: 3
238DVLR IMSI:901700000004620 has MSISDN:46071
239DVLR GSUP tx: 12010809710000004026f0
240GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
241DREF VLR subscr MSISDN:46071 usage decreases to: 2
242<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
243 lu_result_sent == 0
244- having received subscriber data does not mean acceptance
245msc_subscr_conn_is_accepted() == false
246 requests shall be thwarted
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]247DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
248DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
249DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
250DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
251DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
252DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
253DRLL Dispatching 04.08 message GSM48_PDISC_SMS:0x01 (0x9:0x1)
254DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_PDISC_SMS:0x01
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]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: 3
260DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
261DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
262DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
263DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
264DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
265DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
266DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
267DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
268DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
269DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
270DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
271DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
272DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
273DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
274DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
275DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
276DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
277DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
278DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
279DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
280DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
281DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
282- sending LU Accept for MSISDN:46071
283DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
284DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
285DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
286DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
287DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
288DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
289DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]290DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
291DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
292DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
293DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
294DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
295DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
296DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]297DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
298DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
299DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
300DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
301DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
302DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
303DREF MSISDN:46071: MSC conn use - 1 == 0
304DRLL subscr MSISDN:46071: Freeing subscriber connection
305DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]306DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
307DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]308DREF VLR subscr MSISDN:46071 usage decreases to: 1
309<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
310- LU was successful, and the conn has already been closed
311 lu_result_sent == 1
312 llist_count(&net->subscr_conns) == 0
313---
314- subscriber detaches
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]315 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]316 new conn
317DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]318DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]319DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
320DREF VLR subscr MSISDN:46071 usage increases to: 2
321DMM IMSI DETACH for MSISDN:46071
322DREF VLR subscr MSISDN:46071 usage decreases to: 1
323DREF VLR subscr MSISDN:46071 usage decreases to: 0
324DREF freeing VLR subscr MSISDN:46071
325DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]326DREF unknown: MSC conn use - 1 == 0
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]327DRLL Freeing subscriber connection with NULL subscriber
328 llist_count(&net->subscr_conns) == 0
329===== test_two_lu: SUCCESS
330
331full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]332talloc_total_blocks(tall_bsc_ctx) == 9
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]333
334===== test_lu_unknown_tmsi
335- Location Update request with unknown TMSI sends ID Request for IMSI
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]336 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]337 new conn
338DREF unknown: MSC conn use + 1 == 1
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]339DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]340DREF unknown: MSC conn use + 1 == 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]341DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Allocated
342DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
343DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]344DMM LOCATION UPDATING REQUEST: MI(TMSI)=591536962 type=IMSI ATTACH
345DMM LU/new-LAC: 1/0
346DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Allocated
347DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: is child of Subscr_Conn(591536962)
348DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
349DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
350DREF VLR subscr unknown usage increases to: 1
351DVLR New subscr, TMSI: 0x23422342
352DREF VLR subscr TMSI:0x23422342 usage increases to: 2
Neels Hofmeyr0e255582017-07-18 15:39:27 +0200[diff] [blame]353DREF VLR subscr TMSI:0x23422342 usage decreases to: 1
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]354DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
355DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]356DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]357- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051801
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]358- DTAP matches expected message
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]359DMM TMSI:0x23422342: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]360DREF TMSI:0x23422342: MSC conn use - 1 == 1
361 lu_result_sent == 0
362msc_subscr_conn_is_accepted() == false
363 requests shall be thwarted
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]364DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
365DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
366DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
367DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: unknown 0x33
368DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
369DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
370DRLL Dispatching 04.08 message GSM48_PDISC_SMS:0x01 (0x9:0x1)
371DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_PDISC_SMS:0x01
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]372- MS tells us the IMSI, causes a GSUP LU request to HLR
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]373 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]374DREF TMSI:0x23422342: MSC conn use + 1 == 2
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]375DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]376DMM IDENTITY RESPONSE: MI(IMSI)=901700000004620
377DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
378DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
379DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
380DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
381DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
382DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
383DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
384DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
385DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Allocated
386DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
387DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
388DVLR GSUP tx: 04010809710000004026f0
389GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
390DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]391DMM IMSI:901700000004620: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]392DREF IMSI:901700000004620: MSC conn use - 1 == 1
393 lu_result_sent == 0
394- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
395<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
396DVLR GSUP rx 17: 10010809710000004026f00804036470f1
397DREF VLR subscr IMSI:901700000004620 usage increases to: 2
398DVLR IMSI:901700000004620 has MSISDN:46071
399DVLR GSUP tx: 12010809710000004026f0
400GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
401DREF VLR subscr MSISDN:46071 usage decreases to: 1
402<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
403 lu_result_sent == 0
404- having received subscriber data does not mean acceptance
405msc_subscr_conn_is_accepted() == false
406 requests shall be thwarted
Neels Hofmeyrde635e72017-03-10 02:15:20 +0100[diff] [blame^]407DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
408DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
409DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
410DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
411DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
412DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
413DRLL Dispatching 04.08 message GSM48_PDISC_SMS:0x01 (0x9:0x1)
414DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_PDISC_SMS:0x01
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]415 lu_result_sent == 0
416- HLR also sends GSUP _UPDATE_LOCATION_RESULT
417<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
418DVLR GSUP rx 11: 06010809710000004026f0
419DREF VLR subscr MSISDN:46071 usage increases to: 2
420DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
421DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
422DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
423DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
424DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
425DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Freeing instance
426DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Deallocated
427DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
428DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
429DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Allocated
430DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
431DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
432DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
433DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Allocated
434DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(591536962)
435DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
436DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
437DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
438DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(591536962)
439DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Freeing instance
440DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Deallocated
441DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
442- sending LU Accept for MSISDN:46071
443DREF VLR subscr MSISDN:46071 usage increases to: 3
444DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
445DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
446DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
447DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
448DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Freeing instance
449DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Deallocated
450DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]451DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
452DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
453DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
454DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
455DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
456DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
457DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]458DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
459DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(591536962)
460DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
461DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Freeing instance
462DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Deallocated
463DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
464DREF MSISDN:46071: MSC conn use - 1 == 0
465DRLL subscr MSISDN:46071: Freeing subscriber connection
466DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]467DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance
468DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]469DREF VLR subscr MSISDN:46071 usage decreases to: 1
470<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
471- LU was successful, and the conn has already been closed
472 lu_result_sent == 1
473 llist_count(&net->subscr_conns) == 0
474DREF freeing VLR subscr MSISDN:46071
475===== test_lu_unknown_tmsi: SUCCESS
476
477full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyrd489ea32016-05-20 21:59:55 +0200[diff] [blame]478talloc_total_blocks(tall_bsc_ctx) == 9
Neels Hofmeyr3dc2c642017-01-25 15:04:16 +0100[diff] [blame]479
480full talloc report on 'msgb' (total 0 bytes in 1 blocks)
481talloc_total_blocks(tall_bsc_ctx) == 9
482