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