blob: 1b7d2fdfd2f706dda0df45824a8e561a253b6602 [file] [log] [blame]
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +01001===== test_early_stage
Neels Hofmeyr6a29d322017-01-25 15:04:16 +01002- 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
Neels Hofmeyr6166f292017-11-22 14:33:12 +01007DREF unknown: MSC conn use + fsm == 1 (0x4)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +02008DMM 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 Hofmeyr6a29d322017-01-25 15:04:16 +010011msc_subscr_conn_is_accepted() == false
12 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +010013DRLL 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 +010019DRLL 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 +010021- fake: acceptance
22DREF VLR subscr unknown usage increases to: 1
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020023DMM Subscr_Conn(test){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010024 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 Hofmeyr84da6b12016-05-20 21:59:55 +020027DMM 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 Hofmeyr6a29d322017-01-25 15:04:16 +010030DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +020031- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +010032DREF unknown: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010033DRLL subscr unknown: Freeing subscriber connection
34DREF VLR subscr unknown usage decreases to: 0
35DREF freeing VLR subscr unknown
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020036DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Freeing instance
37DMM Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Deallocated
Philipp Maierfbf66102017-04-09 12:32:51 +020038 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010039 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010040===== test_early_stage: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010041
42full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Harald Welte23466192018-02-14 00:19:06 +010043talloc_total_blocks(tall_bsc_ctx) == 7
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010044
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010045===== test_cm_service_without_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010046- CM Service Request without a prior Location Updating
Neels Hofmeyr78ada642017-03-10 02:15:20 +010047 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010048 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +010049DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +010050DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010051DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
Neels Hofmeyr6166f292017-11-22 14:33:12 +010052DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020053DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
54DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
55DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010056DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
57DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
58DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
59DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
60DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_UNIDENT_SUBSCR)
61DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
62DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_UNIDENT_SUBSCR
63- sending CM Service Reject for unknown, result VLR_PR_ARQ_RES_UNIDENT_SUBSCR
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020064DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
65DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_CM_SERVICE_REQ
66DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 2
67DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED
68DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010069DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
70DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
71DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
72DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
73DMM msc_subscr_conn_close(vsub=unknown, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +020074- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +010075DREF unknown: MSC conn use - fsm == 1 (0x1)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020076DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
77DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +010078DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010079DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +020080 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010081- conn was released
82 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010083===== test_cm_service_without_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010084
85full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Harald Welte23466192018-02-14 00:19:06 +010086talloc_total_blocks(tall_bsc_ctx) == 7
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010087
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010088===== test_two_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010089- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +010090 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010091 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +010092DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +010093DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +010094DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +020095DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
96DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
97DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010098DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +010099DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100100DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
101DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
102DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
103DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
104DREF VLR subscr unknown usage increases to: 1
105DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
106DVLR New subscr, IMSI: 901700000004620
107DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200108DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100109DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
110DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
111DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
112DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
113DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
114DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
115DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
116DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
117DVLR GSUP tx: 04010809710000004026f0
118GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
119DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200120DMM IMSI:901700000004620: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100121DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100122 lu_result_sent == 0
123- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
124<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
125DVLR GSUP rx 17: 10010809710000004026f00804036470f1
126DREF VLR subscr IMSI:901700000004620 usage increases to: 2
127DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100128DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100129DVLR GSUP tx: 12010809710000004026f0
130GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
131DREF VLR subscr MSISDN:46071 usage decreases to: 1
132<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
133 lu_result_sent == 0
134- having received subscriber data does not mean acceptance
135msc_subscr_conn_is_accepted() == false
136 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100137DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
138DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
139DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
140DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
141DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
142DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100143DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
144DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100145 lu_result_sent == 0
146- HLR also sends GSUP _UPDATE_LOCATION_RESULT
147<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
148DVLR GSUP rx 11: 06010809710000004026f0
149DREF VLR subscr MSISDN:46071 usage increases to: 2
150DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
151DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
152DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
153DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
154DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
155DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
156DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
157DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
158DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
159DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
160DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
161DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
162DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
163DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
164DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
165DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
166DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
167DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
168DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
169DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
170DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
171DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
172- sending LU Accept for MSISDN:46071
173DREF VLR subscr MSISDN:46071 usage increases to: 3
174DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
175DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
176DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
177DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
178DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
179DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
180DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200181DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
182DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
183DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
184DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
185DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
186DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
187DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100188DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
189DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
190DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
191DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
192DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
193DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200194- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100195DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100196DRLL subscr MSISDN:46071: Freeing subscriber connection
197DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200198DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
199DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100200DREF VLR subscr MSISDN:46071 usage decreases to: 1
201<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200202 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100203- LU was successful, and the conn has already been closed
204 lu_result_sent == 1
205 llist_count(&net->subscr_conns) == 0
206---
207- verify that the MS can send another LU request
208- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100209 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100210 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100211DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100212DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100213DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200214DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
215DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
216DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100217DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100218DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100219DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
220DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
221DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
222DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
223DREF VLR subscr MSISDN:46071 usage increases to: 2
224DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200225DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100226DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
227DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
228DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
229DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
230DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
231DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
232DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
233DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
234DVLR GSUP tx: 04010809710000004026f0
235GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
236DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200237DMM MSISDN:46071: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100238DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100239 lu_result_sent == 0
240- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
241<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
242DVLR GSUP rx 17: 10010809710000004026f00804036470f1
243DREF VLR subscr MSISDN:46071 usage increases to: 3
244DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100245DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=3)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100246DVLR GSUP tx: 12010809710000004026f0
247GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
248DREF VLR subscr MSISDN:46071 usage decreases to: 2
249<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
250 lu_result_sent == 0
251- having received subscriber data does not mean acceptance
252msc_subscr_conn_is_accepted() == false
253 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100254DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
255DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
256DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
257DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
258DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
259DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100260DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
261DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100262 lu_result_sent == 0
263- HLR also sends GSUP _UPDATE_LOCATION_RESULT
264<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
265DVLR GSUP rx 11: 06010809710000004026f0
266DREF VLR subscr MSISDN:46071 usage increases to: 3
267DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
268DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
269DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
270DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
271DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
272DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
273DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
274DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
275DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
276DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
277DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
278DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
279DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
280DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
281DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
282DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
283DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
284DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
285DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
286DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
287DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
288DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
289- sending LU Accept for MSISDN:46071
290DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
291DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
292DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
293DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
294DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
295DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
296DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200297DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
298DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
299DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
300DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
301DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
302DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
303DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100304DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
305DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
306DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
307DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
308DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
309DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200310- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100311DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100312DRLL subscr MSISDN:46071: Freeing subscriber connection
313DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200314DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
315DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100316DREF VLR subscr MSISDN:46071 usage decreases to: 1
317<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200318 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100319- LU was successful, and the conn has already been closed
320 lu_result_sent == 1
321 llist_count(&net->subscr_conns) == 0
322---
323- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100324 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100325 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100326DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100327DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100328DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
329DREF VLR subscr MSISDN:46071 usage increases to: 2
330DMM IMSI DETACH for MSISDN:46071
331DREF VLR subscr MSISDN:46071 usage decreases to: 1
332DREF VLR subscr MSISDN:46071 usage decreases to: 0
333DREF freeing VLR subscr MSISDN:46071
334DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200335- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100336DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100337DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200338 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100339 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100340===== test_two_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100341
342full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Harald Welte23466192018-02-14 00:19:06 +0100343talloc_total_blocks(tall_bsc_ctx) == 7
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100344
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100345===== test_lu_unknown_tmsi
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100346- Location Update request with unknown TMSI sends ID Request for IMSI
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100347 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100348 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100349DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100350DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100351DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200352DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Allocated
353DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
354DMM Subscr_Conn(591536962){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100355DMM LOCATION UPDATING REQUEST: MI(TMSI)=591536962 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100356DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100357DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Allocated
358DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: is child of Subscr_Conn(591536962)
359DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
360DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
361DREF VLR subscr unknown usage increases to: 1
362DVLR New subscr, TMSI: 0x23422342
363DREF VLR subscr TMSI:0x23422342 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200364DREF VLR subscr TMSI:0x23422342 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100365DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
366DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200367DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100368- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051801
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100369- DTAP matches expected message
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200370DMM TMSI:0x23422342: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100371DREF TMSI:0x23422342: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100372 lu_result_sent == 0
373msc_subscr_conn_is_accepted() == false
374 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100375DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
376DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
377DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
378DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: unknown 0x33
379DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
380DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100381DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
382DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100383- MS tells us the IMSI, causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100384 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100385DREF TMSI:0x23422342: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100386DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100387DMM IDENTITY RESPONSE: MI(IMSI)=901700000004620
388DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
389DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
390DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
391DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
392DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
393DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
394DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
395DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
396DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Allocated
397DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
398DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
399DVLR GSUP tx: 04010809710000004026f0
400GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
401DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200402DMM IMSI:901700000004620: bump: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100403DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100404 lu_result_sent == 0
405- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
406<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
407DVLR GSUP rx 17: 10010809710000004026f00804036470f1
408DREF VLR subscr IMSI:901700000004620 usage increases to: 2
409DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100410DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100411DVLR GSUP tx: 12010809710000004026f0
412GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
413DREF VLR subscr MSISDN:46071 usage decreases to: 1
414<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
415 lu_result_sent == 0
416- having received subscriber data does not mean acceptance
417msc_subscr_conn_is_accepted() == false
418 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100419DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
420DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
421DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
422DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
423DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
424DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100425DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
426DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100427 lu_result_sent == 0
428- HLR also sends GSUP _UPDATE_LOCATION_RESULT
429<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
430DVLR GSUP rx 11: 06010809710000004026f0
431DREF VLR subscr MSISDN:46071 usage increases to: 2
432DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
433DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
434DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
435DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
436DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
437DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Freeing instance
438DVLR upd_hlr_vlr_fsm(591536962){UPD_HLR_VLR_S_DONE}: Deallocated
439DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
440DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
441DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Allocated
442DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(591536962)
443DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
444DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
445DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Allocated
446DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(591536962)
447DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
448DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
449DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
450DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(591536962)
451DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Freeing instance
452DVLR sub_pres_vlr_fsm(591536962){SUB_PRES_VLR_S_DONE}: Deallocated
453DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
454- sending LU Accept for MSISDN:46071
455DREF VLR subscr MSISDN:46071 usage increases to: 3
456DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
457DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
458DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
459DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(591536962)
460DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Freeing instance
461DVLR lu_compl_vlr_fsm(591536962){LU_COMPL_VLR_S_DONE}: Deallocated
462DVLR vlr_lu_fsm(591536962){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200463DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
464DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
465DMM Subscr_Conn(591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
466DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
467DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
468DMM Subscr_Conn(591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
469DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100470DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
471DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(591536962)
472DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
473DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Freeing instance
474DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Deallocated
475DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200476- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100477DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100478DRLL subscr MSISDN:46071: Freeing subscriber connection
479DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200480DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance
481DMM Subscr_Conn(591536962){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100482DREF VLR subscr MSISDN:46071 usage decreases to: 1
483<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
Philipp Maierfbf66102017-04-09 12:32:51 +0200484 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100485- LU was successful, and the conn has already been closed
486 lu_result_sent == 1
487 llist_count(&net->subscr_conns) == 0
488DREF freeing VLR subscr MSISDN:46071
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100489===== test_lu_unknown_tmsi: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100490
491full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Harald Welte23466192018-02-14 00:19:06 +0100492talloc_total_blocks(tall_bsc_ctx) == 7
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100493
494full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Harald Welte23466192018-02-14 00:19:06 +0100495talloc_total_blocks(tall_bsc_ctx) == 7
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100496