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