blob: e71295a631c02509229f5596d445ab385ca5ca8a [file] [log] [blame]
Neels Hofmeyr08b38282018-03-30 23:04:04 +02001full talloc report on 'msgb' (total 0 bytes in 1 blocks)
2talloc_total_blocks(tall_bsc_ctx) == 12
3
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +01004===== test_early_stage
Neels Hofmeyr6a29d322017-01-25 15:04:16 +01005- NULL conn
6msc_subscr_conn_is_accepted() == false
7- freshly allocated conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +02008DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +01009msc_subscr_conn_is_accepted() == false
10- conn_fsm present, in state 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 Hofmeyre3d3dc62018-03-31 00:02:14 +020023DMM 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 +010025 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 +020028DMM 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
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020030DREF unknown: MSC conn use + release == 1 (0x100: release)
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020031DREF VLR subscr unknown usage increases to: 2
32DREF VLR subscr unknown usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +020033- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr4068ab22018-04-01 20:55:54 +020034 bssap_clear_sent == 1
35- BSS sends BSSMAP Clear Complete
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020036DREF unknown: MSC conn use - release == 0 (0x0: )
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020037DMM 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 +010043DREF VLR subscr unknown usage decreases to: 0
44DREF freeing VLR subscr unknown
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020045DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance
46DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010047 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010048===== test_early_stage: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010049
50full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +020051talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010052
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010053===== test_cm_service_without_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010054- CM Service Request without a prior Location Updating
Neels Hofmeyr78ada642017-03-10 02:15:20 +010055 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010056 new conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020057DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020058DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
Neels Hofmeyr78ada642017-03-10 02:15:20 +010059DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010060DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020061DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
62DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Allocated
63DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(CM_SERVICE_REQ:901700000004620)
64DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
65DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
Philipp Maier6f4752e2018-05-15 15:23:59 +020066DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(IMSI_UNKNOWN_IN_VLR)
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020067DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
Philipp Maier6f4752e2018-05-15 15:23:59 +020068DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: IMSI_UNKNOWN_IN_VLR
69- sending CM Service Reject for unknown, cause: IMSI_UNKNOWN_IN_VLR
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020070DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
71DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020072DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release)
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020073- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020074DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
75DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_COMPLETE_LAYER_3 not permitted
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020076DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release)
Neels Hofmeyr4068ab22018-04-01 20:55:54 +020077 bssap_clear_sent == 1
78- conn was released
79- BSS sends BSSMAP Clear Complete
Neels Hofmeyr99a8d232018-04-09 20:44:56 +020080DREF unknown: MSC conn use - release == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020081DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
82DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
83DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
84DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
85DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000004620)
86DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Freeing instance
87DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Deallocated
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +020088DRLL Freeing subscriber connection with NULL subscriber
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +020089DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
90DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010091 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010092===== test_cm_service_without_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010093
94full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +020095talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010096
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +010097===== test_two_lu
Neels Hofmeyr6a29d322017-01-25 15:04:16 +010098- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +010099 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100100 new conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200101DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200102DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100103DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200104DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100105DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100106DMM LU/new-LAC: 1/23
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200107DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
108DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
109DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
110DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100111DREF 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 +0200115DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200116DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
117DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
118DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
119DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
120DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
121DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
122DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
123DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100124DVLR GSUP tx: 04010809710000004026f0
125GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200126DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
127DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
128DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200129DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200130DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
131DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100132 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 +0100138DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100139DVLR 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 +0100147DRLL 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 +0100153DRLL 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 +0100155 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
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200160DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
161DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
162DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
163DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
164DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
165DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
166DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
167DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
168DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
169DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
170DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
171DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
172DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
173DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
174DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
175DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
176DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
177DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
178DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
179DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
180DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
181DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100182- sending LU Accept for MSISDN:46071
183DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200184DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
185DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
186DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
187DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
188DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
189DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
190DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
191DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
192DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
193DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
194DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200195DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200196DREF 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 +0200199DREF 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 Hofmeyr99a8d232018-04-09 20:44:56 +0200205DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200206DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
207DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
208DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
209DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
210DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
211DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
212DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
213DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200214DRLL MSISDN:46071: Freeing subscriber connection
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200215DREF VLR subscr MSISDN:46071 usage decreases to: 1
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200216DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
217DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100218 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 +0100222 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100223 new conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200224DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200225DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100226DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200227DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100228DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100229DMM LU/new-LAC: 1/23
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200230DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
231DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
232DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
233DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100234DREF VLR subscr MSISDN:46071 usage increases to: 2
235DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200236DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200237DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
238DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
239DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
240DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
241DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
242DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
243DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
244DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100245DVLR GSUP tx: 04010809710000004026f0
246GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200247DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
248DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
249DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200250DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200251DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
252DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100253 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 +0100259DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=3)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100260DVLR 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 +0100268DRLL 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 +0100274DRLL 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 +0100276 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
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200281DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
282DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
283DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
284DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
285DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
286DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
287DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
288DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
289DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
290DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
291DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
292DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
293DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
294DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
295DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
296DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
297DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
298DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
299DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
300DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
301DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
302DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100303- sending LU Accept for MSISDN:46071
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200304DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
305DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
306DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
307DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
308DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
309DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
310DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
311DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
312DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
313DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
314DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200315DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200316DREF 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 +0200319DREF 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 Hofmeyr99a8d232018-04-09 20:44:56 +0200325DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200326DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
327DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
328DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
329DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
330DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
331DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
332DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
333DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200334DRLL MSISDN:46071: Freeing subscriber connection
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200335DREF VLR subscr MSISDN:46071 usage decreases to: 1
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200336DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
337DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100338 llist_count(&net->subscr_conns) == 0
339---
340- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100341 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100342 new conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200343DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200344DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100345DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100346DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
347DREF VLR subscr MSISDN:46071 usage increases to: 2
348DMM IMSI DETACH for MSISDN:46071
Neels Hofmeyr15809592018-04-06 02:57:51 +0200349DREF VLR subscr MSISDN:46071 usage increases to: 3
350DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100351DREF VLR subscr MSISDN:46071 usage decreases to: 1
352DREF VLR subscr MSISDN:46071 usage decreases to: 0
353DREF freeing VLR subscr MSISDN:46071
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200354DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200355DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200356DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release)
Philipp Maierfbf66102017-04-09 12:32:51 +0200357- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200358DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release)
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200359 bssap_clear_sent == 1
360- BSS sends BSSMAP Clear Complete
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200361DREF unknown: MSC conn use - release == 0 (0x0: )
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200362DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
363DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
364DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100365DRLL Freeing subscriber connection with NULL subscriber
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200366DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance
367DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100368 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100369===== test_two_lu: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100370
371full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200372talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100373
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100374===== test_lu_unknown_tmsi
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100375- Location Update request with unknown TMSI sends ID Request for IMSI
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100376 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100377 new conn
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200378DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200379DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100380DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200381DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_NEW}: Updated ID
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100382DMM LOCATION UPDATING REQUEST: MI(TMSI)=591536962 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100383DMM LU/new-LAC: 1/23
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200384DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: Allocated
385DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:591536962)
386DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
387DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100388DREF VLR subscr unknown usage increases to: 1
389DVLR New subscr, TMSI: 0x23422342
390DREF VLR subscr TMSI:0x23422342 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200391DREF VLR subscr TMSI:0x23422342 usage decreases to: 1
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200392DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
393DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200394DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100395- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051801
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100396- DTAP matches expected message
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200397DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
398DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200399DREF TMSI:0x23422342: MSC conn use - compl_l3 == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200400DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
401DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100402 lu_result_sent == 0
403msc_subscr_conn_is_accepted() == false
404 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100405DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
406DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
407DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
408DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: unknown 0x33
409DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
410DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100411DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
412DRLL subscr TMSI:0x23422342: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100413- MS tells us the IMSI, causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100414 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200415DREF TMSI:0x23422342: MSC conn use + dtap == 1 (0x2: dtap)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100416DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100417DMM IDENTITY RESPONSE: MI(IMSI)=901700000004620
418DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200419DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100420DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200421DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
422DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
423DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
424DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
425DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
426DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_INIT}: Allocated
427DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:591536962)
428DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100429DVLR GSUP tx: 04010809710000004026f0
430GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200431DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200432DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200433DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
434DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100435 lu_result_sent == 0
436- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
437<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
438DVLR GSUP rx 17: 10010809710000004026f00804036470f1
439DREF VLR subscr IMSI:901700000004620 usage increases to: 2
440DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100441DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100442DVLR GSUP tx: 12010809710000004026f0
443GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
444DREF VLR subscr MSISDN:46071 usage decreases to: 1
445<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
446 lu_result_sent == 0
447- having received subscriber data does not mean acceptance
448msc_subscr_conn_is_accepted() == false
449 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100450DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
451DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
452DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
453DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
454DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
455DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100456DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
457DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100458 lu_result_sent == 0
459- HLR also sends GSUP _UPDATE_LOCATION_RESULT
460<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
461DVLR GSUP rx 11: 06010809710000004026f0
462DREF VLR subscr MSISDN:46071 usage increases to: 2
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200463DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
464DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
465DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
466DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
467DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:591536962)
468DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_DONE}: Freeing instance
469DVLR upd_hlr_vlr_fsm(LU:591536962){UPD_HLR_VLR_S_DONE}: Deallocated
470DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
471DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
472DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_INIT}: Allocated
473DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:591536962)
474DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
475DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
476DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_INIT}: Allocated
477DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:591536962)
478DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
479DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
480DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
481DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:591536962)
482DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_DONE}: Freeing instance
483DVLR sub_pres_vlr_fsm(LU:591536962){SUB_PRES_VLR_S_DONE}: Deallocated
484DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100485- sending LU Accept for MSISDN:46071
486DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200487DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
488DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
489DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
490DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:591536962)
491DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_DONE}: Freeing instance
492DVLR lu_compl_vlr_fsm(LU:591536962){LU_COMPL_VLR_S_DONE}: Deallocated
493DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
494DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
495DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
496DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
497DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200498DREF MSISDN:46071: MSC conn use + release == 1 (0x100: release)
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200499DREF VLR subscr MSISDN:46071 usage increases to: 4
500DREF VLR subscr MSISDN:46071 usage decreases to: 3
501- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200502DREF VLR subscr MSISDN:46071 usage decreases to: 2
503<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
504 bssap_clear_sent == 1
505- LU was successful, and the conn has already been closed
506 lu_result_sent == 1
507- BSS sends BSSMAP Clear Complete
Neels Hofmeyr99a8d232018-04-09 20:44:56 +0200508DREF MSISDN:46071: MSC conn use - release == 0 (0x0: )
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200509DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
510DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
511DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
512DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
513DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:591536962)
514DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
515DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_DONE}: Freeing instance
516DVLR vlr_lu_fsm(LU:591536962){VLR_ULA_S_DONE}: Deallocated
Neels Hofmeyre3d3dc62018-03-31 00:02:14 +0200517DRLL MSISDN:46071: Freeing subscriber connection
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200518DREF VLR subscr MSISDN:46071 usage decreases to: 1
Neels Hofmeyrfe4ba7c2018-04-02 23:17:50 +0200519DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance
520DMM Subscr_Conn(LU:591536962){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100521 llist_count(&net->subscr_conns) == 0
522DREF freeing VLR subscr MSISDN:46071
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100523===== test_lu_unknown_tmsi: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100524
525full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200526talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100527
528full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200529talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100530