Gitiles
Code Review Sign In
gerrit.osmocom.org / osmo-msc / 79beccd93a27796a2ca9be201a5b9cf3695fbf5c / . / tests / msc_vlr / msc_vlr_test_no_authen.err
blob: be2d537b09fc047c78200c4cd2c31bd4cbc8bead [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_no_authen
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]5- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]6 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]7 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]8DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]9DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]10DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]11DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
12DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
13DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]14DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]15DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]16DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]17DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
18DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
19DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
20DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
21DREF VLR subscr unknown usage increases to: 1
22DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
23DVLR New subscr, IMSI: 901700000004620
24DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200[diff] [blame]25DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]26DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
27DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
28DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
29DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
30DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
31DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
32DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
33DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
34DVLR GSUP tx: 04010809710000004026f0
35GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
36DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]37DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]38DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]39 lu_result_sent == 0
40- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
41<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
42DVLR GSUP rx 17: 10010809710000004026f00804036470f1
43DREF VLR subscr IMSI:901700000004620 usage increases to: 2
44DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]45DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]46DVLR GSUP tx: 12010809710000004026f0
47GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
48DREF VLR subscr MSISDN:46071 usage decreases to: 1
49<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
50 lu_result_sent == 0
51- having received subscriber data does not mean acceptance
52msc_subscr_conn_is_accepted() == false
53 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]54DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
55DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
56DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
57DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
58DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
59DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]60DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
61DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]62 lu_result_sent == 0
63- HLR also sends GSUP _UPDATE_LOCATION_RESULT
64<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
65DVLR GSUP rx 11: 06010809710000004026f0
66DREF VLR subscr MSISDN:46071 usage increases to: 2
67DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
68DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
69DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
70DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
71DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
72DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
73DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
74DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
75DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
76DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
77DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
78DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
79DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
80DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
81DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
82DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
83DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
84DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
85DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
86DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
87DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
88DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
89- sending LU Accept for MSISDN:46071
90DREF VLR subscr MSISDN:46071 usage increases to: 3
91DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
92DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
93DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
94DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
95DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
96DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
97DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]98DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]99DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]100DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
101DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]102DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
103DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]104DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
105DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
106DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
107DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
108DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
109DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]110- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]111DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]112DRLL subscr MSISDN:46071: Freeing subscriber connection
113DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]114DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
115DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]116DREF VLR subscr MSISDN:46071 usage decreases to: 1
117<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
118- LU was successful, and the conn has already been closed
119 lu_result_sent == 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]120 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]121 llist_count(&net->subscr_conns) == 0
122---
123- after a while, a new conn sends a CM Service Request
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]124 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]125 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]126DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]127DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]128DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]129DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]130DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
131DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
132DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]133DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from CM_SERVICE_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]134DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
135DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
136DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
137DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
138DREF VLR subscr MSISDN:46071 usage increases to: 2
139DREF VLR subscr MSISDN:46071 usage increases to: 3
140DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
141DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
142DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
143DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
144DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
145DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
146DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
147DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_PASSED)
148DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
149DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_PASSED
150- sending CM Service Accept for MSISDN:46071
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]151DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]152DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
153DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]154DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
155DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: still awaiting first request after a CM Service Request
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]156DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]157DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
158DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: still awaiting first request after a CM Service Request
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]159DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]160 cm_service_result_sent == 1
161msc_subscr_conn_is_accepted() == true
162- a USSD request is serviced
163 expecting USSD:
164 Your extension is 46071
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]165 MSC <--RAN_GERAN_A-- MS: NCSS:0x3b
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]166DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]167DRLL Dispatching 04.08 message NCSS:0x3b (0xb:0x3b)
168DMM MSISDN:46071: rx msg NCSS:0x3b: received_cm_service_request changes to false
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]169DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
170DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]171DMM USSD: Own number requested
172DMM MSISDN:46071: MSISDN = 46071
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]173DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]174- DTAP --RAN_GERAN_A--> MS: NCSS:0x2a: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]175- DTAP matches expected message
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]176DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
177DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]178DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
179DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]180DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
181DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
182DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
183DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
184DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]185- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]186DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]187DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
188DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]189DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]190DRLL subscr MSISDN:46071: Freeing subscriber connection
191DREF VLR subscr MSISDN:46071 usage decreases to: 1
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]192 dtap_tx_confirmed == 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]193 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]194- all requests serviced, conn has been released
195 llist_count(&net->subscr_conns) == 0
196---
197- an SMS is sent, MS is paged
198DREF VLR subscr MSISDN:46071 usage increases to: 2
199 llist_count(&vsub->cs.requests) == 0
200DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]201DMM Subscriber MSISDN:46071 not paged yet, start paging.
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]202 RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]203 strcmp(paging_expecting_imsi, imsi) == 0
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]204DREF VLR subscr MSISDN:46071 usage increases to: 4
205 llist_count(&vsub->cs.requests) == 1
206DREF VLR subscr MSISDN:46071 usage decreases to: 3
207 paging_sent == 1
208 paging_stopped == 0
209- the subscriber and its pending request should remain
210DREF VLR subscr MSISDN:46071 usage increases to: 4
211 llist_count(&vsub->cs.requests) == 1
212DREF VLR subscr MSISDN:46071 usage decreases to: 3
213- MS replies with Paging Response, we deliver the SMS
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]214 MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]215 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]216DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]217DRLL Dispatching 04.08 message GSM48_MT_RR_PAG_RESP (0x6:0x27)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]218DRR PAGING RESPONSE: MI(IMSI)=901700000004620
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]219DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]220DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
221DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
222DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]223DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from PAGING_RESP
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]224DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Allocated
225DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(901700000004620)
226DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
227DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
228DREF VLR subscr MSISDN:46071 usage increases to: 4
229DREF VLR subscr MSISDN:46071 usage increases to: 5
230DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
231DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
232DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
233DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
234DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
235DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
236DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
237DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_PASSED)
238DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
239DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_PASSED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]240DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]241DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
242DPAG Paging success for MSISDN:46071 (event=0)
243DPAG Calling paging cbfn.
Neels Hofmeyr12e17be2018-03-12 23:59:37 +0100[diff] [blame]244DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]245DREF VLR subscr MSISDN:46071 usage increases to: 6
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]246DREF MSISDN:46071: MSC conn use + trans_sms == 3 (0x15)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]247DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]248- DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]249- DTAP matches expected message
250DREF VLR subscr MSISDN:46071 usage decreases to: 5
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]251DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
252DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]253DREF VLR subscr MSISDN:46071 usage decreases to: 4
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]254DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
255DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]256DREF MSISDN:46071: MSC conn use - compl_l3 == 2 (0x14)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]257 dtap_tx_confirmed == 1
258 paging_stopped == 1
259- SMS was delivered, no requests pending for subscr
260DREF VLR subscr MSISDN:46071 usage increases to: 5
261 llist_count(&vsub->cs.requests) == 0
262DREF VLR subscr MSISDN:46071 usage decreases to: 4
263- conn is still open to wait for SMS ack dance
264 llist_count(&net->subscr_conns) == 1
265- MS replies with CP-ACK for received SMS
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]266 MSC <--RAN_GERAN_A-- MS: SMS:0x04
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]267DREF MSISDN:46071: MSC conn use + dtap == 3 (0x16)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]268DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]269DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
270DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]271DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
272DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]273DREF MSISDN:46071: MSC conn use - dtap == 2 (0x14)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]274 llist_count(&net->subscr_conns) == 1
275- MS also sends RP-ACK, MSC in turn sends CP-ACK for that
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]276 MSC <--RAN_GERAN_A-- MS: SMS:0x01
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]277DREF MSISDN:46071: MSC conn use + dtap == 3 (0x16)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]278DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]279DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
280DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]281- DTAP --RAN_GERAN_A--> MS: SMS:0x04: 0904
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]282- DTAP matches expected message
283DREF VLR subscr MSISDN:46071 usage decreases to: 3
284DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]285DREF MSISDN:46071: MSC conn use - trans_sms == 2 (0x6)
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]286DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
287DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]288DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
289DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]290DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
291DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
292DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
293DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
294DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]295- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]296DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]297DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
298DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]299DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]300DRLL subscr MSISDN:46071: Freeing subscriber connection
301DREF VLR subscr MSISDN:46071 usage decreases to: 1
302 dtap_tx_confirmed == 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]303 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]304- SMS is done, conn is gone
305 llist_count(&net->subscr_conns) == 0
306---
307- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]308 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]309 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]310DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]311DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]312DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
313DREF VLR subscr MSISDN:46071 usage increases to: 2
314DMM IMSI DETACH for MSISDN:46071
315DREF VLR subscr MSISDN:46071 usage decreases to: 1
316DREF VLR subscr MSISDN:46071 usage decreases to: 0
317DREF freeing VLR subscr MSISDN:46071
318DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]319- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]320DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]321DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]322 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]323 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]324===== test_no_authen: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]325
326full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]327talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]328
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]329===== test_no_authen_tmsi
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]330- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]331 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]332 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]333DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]334DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]335DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]336DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
337DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
338DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]339DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]340DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]341DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]342DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
343DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
344DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
345DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
346DREF VLR subscr unknown usage increases to: 1
347DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
348DVLR New subscr, IMSI: 901700000004620
349DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200[diff] [blame]350DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]351DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
352DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
353DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
354DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
355DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
356DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
357DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
358DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
359DVLR GSUP tx: 04010809710000004026f0
360GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
361DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]362DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]363DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]364 lu_result_sent == 0
365- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
366<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
367DVLR GSUP rx 17: 10010809710000004026f00804036470f1
368DREF VLR subscr IMSI:901700000004620 usage increases to: 2
369DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]370DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]371DVLR GSUP tx: 12010809710000004026f0
372GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
373DREF VLR subscr MSISDN:46071 usage decreases to: 1
374<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
375 lu_result_sent == 0
376- having received subscriber data does not mean acceptance
377msc_subscr_conn_is_accepted() == false
378 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]379DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
380DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
381DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
382DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
383DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
384DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]385DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
386DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]387 lu_result_sent == 0
388- HLR also sends GSUP _UPDATE_LOCATION_RESULT
389<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
390DVLR GSUP rx 11: 06010809710000004026f0
391DREF VLR subscr MSISDN:46071 usage increases to: 2
392DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
393DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
394DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
395DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
396DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
397DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
398DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
399DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
400DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
401DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
402DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
403DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
404DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
405DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
406DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
407DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
408DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
409DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
410DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
411DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
412DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
413DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
414DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
415DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
416- sending LU Accept for MSISDN:46071, with TMSI 0x03020100
417DREF VLR subscr MSISDN:46071 usage decreases to: 1
418<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
419- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
420 llist_count(&net->subscr_conns) == 1
421 lu_result_sent == 1
422msc_subscr_conn_is_accepted() == false
423 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]424DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
425DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
426DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
427DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
428DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
429DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]430DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
431DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]432- even though the TMSI is not acked, we can already find the subscr with it
433DREF VLR subscr MSISDN:46071 usage increases to: 2
434 vsub != NULL == 1
435 strcmp(vsub->imsi, imsi) == 0
436 vsub->tmsi_new == 0x03020100
437 vsub->tmsi == 0xffffffff
438DREF VLR subscr MSISDN:46071 usage decreases to: 1
439- MS sends TMSI Realloc Complete
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]440 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]441DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]442DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]443DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
444DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
445DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
446DREF VLR subscr MSISDN:46071 usage increases to: 2
447DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
448DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
449DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
450DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
451DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
452DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
453DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]454DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]455DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]456DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
457DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]458DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
459DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]460DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
461DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
462DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
463DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
464DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
465DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]466- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]467DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]468DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
469DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]470DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]471DRLL subscr MSISDN:46071: Freeing subscriber connection
472DREF VLR subscr MSISDN:46071 usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]473 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]474- LU was successful, and the conn has already been closed
475 llist_count(&net->subscr_conns) == 0
476- Subscriber has the new TMSI
477DREF VLR subscr MSISDN:46071 usage increases to: 2
478 vsub != NULL == 1
479 strcmp(vsub->imsi, imsi) == 0
480 vsub->tmsi_new == 0xffffffff
481 vsub->tmsi == 0x03020100
482DREF VLR subscr MSISDN:46071 usage decreases to: 1
483---
484- after a while, a new conn sends a CM Service Request using above TMSI
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]485 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]486 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]487DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]488DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]489DMM <- CM SERVICE REQUEST serv_type=0x08 MI(TMSI)=50462976
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]490DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]491DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Allocated
492DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
493DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]494DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Updated ID from CM_SERVICE_REQ
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]495DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: Allocated
496DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: is child of Subscr_Conn(50462976)
497DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
498DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
499DREF VLR subscr MSISDN:46071 usage increases to: 2
500DREF VLR subscr MSISDN:46071 usage increases to: 3
501DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
502DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
503DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
504DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
505DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
506DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
507DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
508DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_PASSED)
509DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
510DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_PASSED
511- sending CM Service Accept for MSISDN:46071
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]512DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]513DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
514DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]515DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
516DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: still awaiting first request after a CM Service Request
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]517DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]518DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
519DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: still awaiting first request after a CM Service Request
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]520DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]521 cm_service_result_sent == 1
522msc_subscr_conn_is_accepted() == true
523- a USSD request is serviced
524 expecting USSD:
525 Your extension is 46071
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]526 MSC <--RAN_GERAN_A-- MS: NCSS:0x3b
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]527DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]528DRLL Dispatching 04.08 message NCSS:0x3b (0xb:0x3b)
529DMM MSISDN:46071: rx msg NCSS:0x3b: received_cm_service_request changes to false
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]530DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
531DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]532DMM USSD: Own number requested
533DMM MSISDN:46071: MSISDN = 46071
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]534DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]535- DTAP --RAN_GERAN_A--> MS: NCSS:0x2a: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]536- DTAP matches expected message
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]537DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
538DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]539DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
540DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]541DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
542DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(50462976)
543DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance
544DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated
545DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]546- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]547DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]548DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
549DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]550DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]551DRLL subscr MSISDN:46071: Freeing subscriber connection
552DREF VLR subscr MSISDN:46071 usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]553 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]554- all requests serviced, conn has been released
555 llist_count(&net->subscr_conns) == 0
556---
557- an SMS is sent, MS is paged using above TMSI
558DREF VLR subscr MSISDN:46071 usage increases to: 2
559 llist_count(&vsub->cs.requests) == 0
560DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]561DMM Subscriber MSISDN:46071 not paged yet, start paging.
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]562 RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]563 paging_expecting_tmsi == 0x03020100
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]564DREF VLR subscr MSISDN:46071 usage increases to: 4
565 llist_count(&vsub->cs.requests) == 1
566DREF VLR subscr MSISDN:46071 usage decreases to: 3
567 paging_sent == 1
568 paging_stopped == 0
569- the subscriber and its pending request should remain
570DREF VLR subscr MSISDN:46071 usage increases to: 4
571 llist_count(&vsub->cs.requests) == 1
572DREF VLR subscr MSISDN:46071 usage decreases to: 3
573- MS replies with Paging Response using TMSI, we deliver the SMS
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]574 MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]575 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]576DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]577DRLL Dispatching 04.08 message GSM48_MT_RR_PAG_RESP (0x6:0x27)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]578DRR PAGING RESPONSE: MI(TMSI)=50462976
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]579DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]580DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Allocated
581DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
582DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]583DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Updated ID from PAGING_RESP
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]584DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: Allocated
585DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: is child of Subscr_Conn(50462976)
586DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
587DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
588DREF VLR subscr MSISDN:46071 usage increases to: 4
589DREF VLR subscr MSISDN:46071 usage increases to: 5
590DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
591DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
592DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
593DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_vlr()
594DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_pres()
595DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_trace()
596DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_post_imei()
597DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: proc_arq_fsm_done(VLR_PR_ARQ_RES_PASSED)
598DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_DONE
599DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Process Access Request result: VLR_PR_ARQ_RES_PASSED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]600DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]601DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
602DPAG Paging success for MSISDN:46071 (event=0)
603DPAG Calling paging cbfn.
Neels Hofmeyr12e17be2018-03-12 23:59:37 +0100[diff] [blame]604DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]605DREF VLR subscr MSISDN:46071 usage increases to: 6
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]606DREF MSISDN:46071: MSC conn use + trans_sms == 3 (0x15)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]607DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]608- DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]609- DTAP matches expected message
610DREF VLR subscr MSISDN:46071 usage decreases to: 5
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]611DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
612DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]613DREF VLR subscr MSISDN:46071 usage decreases to: 4
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]614DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
615DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]616DREF MSISDN:46071: MSC conn use - compl_l3 == 2 (0x14)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]617 dtap_tx_confirmed == 1
618 paging_stopped == 1
619- SMS was delivered, no requests pending for subscr
620DREF VLR subscr MSISDN:46071 usage increases to: 5
621 llist_count(&vsub->cs.requests) == 0
622DREF VLR subscr MSISDN:46071 usage decreases to: 4
623- conn is still open to wait for SMS ack dance
624 llist_count(&net->subscr_conns) == 1
625- MS replies with CP-ACK for received SMS
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]626 MSC <--RAN_GERAN_A-- MS: SMS:0x04
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]627DREF MSISDN:46071: MSC conn use + dtap == 3 (0x16)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]628DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]629DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
630DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]631DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
632DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: connection still has active transaction: SMS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]633DREF MSISDN:46071: MSC conn use - dtap == 2 (0x14)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]634 llist_count(&net->subscr_conns) == 1
635- MS also sends RP-ACK, MSC in turn sends CP-ACK for that
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]636 MSC <--RAN_GERAN_A-- MS: SMS:0x01
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]637DREF MSISDN:46071: MSC conn use + dtap == 3 (0x16)
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]638DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]639DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
640DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]641- DTAP --RAN_GERAN_A--> MS: SMS:0x04: 0904
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]642- DTAP matches expected message
643DREF VLR subscr MSISDN:46071 usage decreases to: 3
644DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]645DREF MSISDN:46071: MSC conn use - trans_sms == 2 (0x6)
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]646DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
647DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]648DMM Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
649DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]650DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
651DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(50462976)
652DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance
653DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated
654DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]655- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]656DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]657DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
658DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]659DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]660DRLL subscr MSISDN:46071: Freeing subscriber connection
661DREF VLR subscr MSISDN:46071 usage decreases to: 1
662 dtap_tx_confirmed == 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]663 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]664- SMS is done, conn is gone
665 llist_count(&net->subscr_conns) == 0
666---
667- subscriber sends LU Request, this time with the TMSI
668- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]669 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]670 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]671DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]672DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]673DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]674DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Allocated
675DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
676DMM Subscr_Conn(50462976){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]677DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]678DMM LOCATION UPDATING REQUEST: MI(TMSI)=50462976 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]679DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]680DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: Allocated
681DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: is child of Subscr_Conn(50462976)
682DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
683DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
684DREF VLR subscr MSISDN:46071 usage increases to: 2
685DREF VLR subscr MSISDN:46071 usage increases to: 3
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200[diff] [blame]686DREF VLR subscr MSISDN:46071 usage decreases to: 2
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]687DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
688DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
689DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
690DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
691DVLR vlr_lu_fsm(50462976){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
692DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_INIT}: Allocated
693DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(50462976)
694DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
695DVLR GSUP tx: 04010809710000004026f0
696GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
697DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]698DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]699DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]700 lu_result_sent == 0
701- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
702<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
703DVLR GSUP rx 17: 10010809710000004026f00804036470f1
704DREF VLR subscr MSISDN:46071 usage increases to: 3
705DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]706DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=3)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]707DVLR GSUP tx: 12010809710000004026f0
708GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
709DREF VLR subscr MSISDN:46071 usage decreases to: 2
710<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
711 lu_result_sent == 0
712- having received subscriber data does not mean acceptance
713msc_subscr_conn_is_accepted() == false
714 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]715DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
716DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
717DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
718DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
719DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
720DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]721DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
722DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]723 lu_result_sent == 0
724- HLR also sends GSUP _UPDATE_LOCATION_RESULT
725<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
726DVLR GSUP rx 11: 06010809710000004026f0
727DREF VLR subscr MSISDN:46071 usage increases to: 3
728DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
729DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
730DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
731DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
732DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(50462976)
733DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_DONE}: Freeing instance
734DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_DONE}: Deallocated
735DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
736DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
737DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_INIT}: Allocated
738DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(50462976)
739DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
740DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
741DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_INIT}: Allocated
742DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(50462976)
743DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
744DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
745DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
746DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(50462976)
747DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_DONE}: Freeing instance
748DVLR sub_pres_vlr_fsm(50462976){SUB_PRES_VLR_S_DONE}: Deallocated
749DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
750DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
751DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
752- sending LU Accept for MSISDN:46071, with TMSI 0x07060504
753DREF VLR subscr MSISDN:46071 usage decreases to: 2
754<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
755- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
756 llist_count(&net->subscr_conns) == 1
757 lu_result_sent == 1
758msc_subscr_conn_is_accepted() == false
759 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]760DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
761DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
762DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
763DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
764DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
765DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]766DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
767DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]768- even though the TMSI is not acked, we can already find the subscr with it
769DREF VLR subscr MSISDN:46071 usage increases to: 3
770 vsub != NULL == 1
771 strcmp(vsub->imsi, imsi) == 0
772 vsub->tmsi_new == 0x07060504
773 vsub->tmsi == 0x03020100
774DREF VLR subscr MSISDN:46071 usage decreases to: 2
775- MS sends TMSI Realloc Complete
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]776 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]777DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]778DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]779DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
780DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
781DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
782DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
783DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
784DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
785DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(50462976)
786DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_DONE}: Freeing instance
787DVLR lu_compl_vlr_fsm(50462976){LU_COMPL_VLR_S_DONE}: Deallocated
788DVLR vlr_lu_fsm(50462976){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]789DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]790DMM Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]791DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
792DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]793DMM Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
794DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]795DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
796DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(50462976)
797DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
798DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Freeing instance
799DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Deallocated
800DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]801- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]802DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]803DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
804DMM Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]805DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]806DRLL subscr MSISDN:46071: Freeing subscriber connection
807DREF VLR subscr MSISDN:46071 usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]808 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]809- LU was successful, and the conn has already been closed
810 llist_count(&net->subscr_conns) == 0
811- subscriber has the new TMSI
812DREF VLR subscr MSISDN:46071 usage increases to: 2
813 vsub != NULL == 1
814 strcmp(vsub->imsi, imsi) == 0
815 vsub->tmsi_new == 0xffffffff
816 vsub->tmsi == 0x07060504
817DREF VLR subscr MSISDN:46071 usage decreases to: 1
818---
819- subscriber detaches, using new TMSI
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]820 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]821 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]822DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]823DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]824DMM IMSI DETACH INDICATION: MI(TMSI)=117835012
825DREF VLR subscr MSISDN:46071 usage increases to: 2
826DMM IMSI DETACH for MSISDN:46071
827DREF VLR subscr MSISDN:46071 usage decreases to: 1
828DREF VLR subscr MSISDN:46071 usage decreases to: 0
829DREF freeing VLR subscr MSISDN:46071
830DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]831- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]832DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]833DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]834 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]835 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]836===== test_no_authen_tmsi: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]837
838full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]839talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]840
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]841===== test_no_authen_imei
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]842- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]843 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]844 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]845DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]846DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]847DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]848DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
849DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
850DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]851DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]852DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]853DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]854DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
855DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
856DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
857DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
858DREF VLR subscr unknown usage increases to: 1
859DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
860DVLR New subscr, IMSI: 901700000004620
861DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200[diff] [blame]862DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]863DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
864DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
865DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
866DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
867DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
868DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
869DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
870DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
871DVLR GSUP tx: 04010809710000004026f0
872GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
873DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]874DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]875DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]876 lu_result_sent == 0
877- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
878<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
879DVLR GSUP rx 17: 10010809710000004026f00804036470f1
880DREF VLR subscr IMSI:901700000004620 usage increases to: 2
881DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]882DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]883DVLR GSUP tx: 12010809710000004026f0
884GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
885DREF VLR subscr MSISDN:46071 usage decreases to: 1
886<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
887 lu_result_sent == 0
888- having received subscriber data does not mean acceptance
889msc_subscr_conn_is_accepted() == false
890 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]891DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
892DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
893DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
894DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
895DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
896DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]897DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
898DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]899 lu_result_sent == 0
900- HLR also sends GSUP _UPDATE_LOCATION_RESULT, and we send an ID Request for the IMEI to the MS
901<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
902DVLR GSUP rx 11: 06010809710000004026f0
903DREF VLR subscr MSISDN:46071 usage increases to: 2
904DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
905DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
906DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
907DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
908DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
909DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
910DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
911DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
912DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
913DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
914DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
915DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
916DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
917DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
918DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
919DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
920DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
921DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
922DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
923DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
924DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
925DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
926DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]927DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]928- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051802
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]929- DTAP matches expected message
930DREF VLR subscr MSISDN:46071 usage decreases to: 1
931<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
932- We will only do business when the IMEI is known
933 llist_count(&net->subscr_conns) == 1
934DREF VLR subscr MSISDN:46071 usage increases to: 2
935 vsub->imei[0] == 0
936DREF VLR subscr MSISDN:46071 usage decreases to: 1
937msc_subscr_conn_is_accepted() == false
938 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]939DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
940DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
941DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
942DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
943DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
944DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]945DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
946DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]947- MS replies with an Identity Response
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]948 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]949DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]950DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]951DMM IDENTITY RESPONSE: MI(IMEI)=423423423423420
952DVLR set IMEI on subscriber; IMSI=901700000004620 IMEI=423423423423420
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]953DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_ID_IMEI
954DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK
955- sending LU Accept for MSISDN:46071
956DREF VLR subscr MSISDN:46071 usage increases to: 2
957DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI}: state_chg to LU_COMPL_VLR_S_DONE
958DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
959DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
960DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
961DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
962DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
963DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]964DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]965DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]966DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
967DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]968DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
969DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]970DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
971DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
972DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
973DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
974DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
975DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]976- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]977DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]978DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
979DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]980DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]981DRLL subscr MSISDN:46071: Freeing subscriber connection
982DREF VLR subscr MSISDN:46071 usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]983 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]984- LU was successful, and the conn has already been closed
985 lu_result_sent == 1
986 llist_count(&net->subscr_conns) == 0
987- Subscriber has the IMEI
988DREF VLR subscr MSISDN:46071 usage increases to: 2
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]989 strcmp(vsub->imei, "423423423423420") == 0
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]990DREF VLR subscr MSISDN:46071 usage decreases to: 1
991---
992- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]993 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]994 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]995DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]996DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]997DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
998DREF VLR subscr MSISDN:46071 usage increases to: 2
999DMM IMSI DETACH for MSISDN:46071
1000DREF VLR subscr MSISDN:46071 usage decreases to: 1
1001DREF VLR subscr MSISDN:46071 usage decreases to: 0
1002DREF freeing VLR subscr MSISDN:46071
1003DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1004- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1005DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1006DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1007 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1008 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1009===== test_no_authen_imei: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1010
1011full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]1012talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1013
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1014===== test_no_authen_tmsi_imei
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1015- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1016 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1017 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1018DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1019DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1020DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1021DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1022DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1023DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1024DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1025DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1026DMM LU/new-LAC: 1/23
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1027DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1028DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1029DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1030DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1031DREF VLR subscr unknown usage increases to: 1
1032DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
1033DVLR New subscr, IMSI: 901700000004620
1034DREF VLR subscr IMSI:901700000004620 usage increases to: 2
Neels Hofmeyr54a706c2017-07-18 15:39:27 +0200[diff] [blame]1035DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1036DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
1037DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
1038DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
1039DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
1040DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1041DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1042DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1043DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1044DVLR GSUP tx: 04010809710000004026f0
1045GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1046DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1047DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1048DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1049 lu_result_sent == 0
1050- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1051<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1052DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1053DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1054DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1055DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1056DVLR GSUP tx: 12010809710000004026f0
1057GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1058DREF VLR subscr MSISDN:46071 usage decreases to: 1
1059<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1060 lu_result_sent == 0
1061- having received subscriber data does not mean acceptance
1062msc_subscr_conn_is_accepted() == false
1063 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1064DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1065DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1066DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1067DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1068DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1069DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1070DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1071DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1072 lu_result_sent == 0
1073- HLR also sends GSUP _UPDATE_LOCATION_RESULT, and we send an ID Request for the IMEI to the MS
1074<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1075DVLR GSUP rx 11: 06010809710000004026f0
1076DREF VLR subscr MSISDN:46071 usage increases to: 2
1077DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1078DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1079DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1080DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1081DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1082DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
1083DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
1084DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
1085DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
1086DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
1087DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1088DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
1089DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
1090DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
1091DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
1092DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
1093DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
1094DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1095DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
1096DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
1097DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
1098DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
1099DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI_TMSI
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1100DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1101- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051802
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1102- DTAP matches expected message
1103DREF VLR subscr MSISDN:46071 usage decreases to: 1
1104<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
1105- We will only do business when the IMEI is known
1106 llist_count(&net->subscr_conns) == 1
1107DREF VLR subscr MSISDN:46071 usage increases to: 2
1108 vsub->imei[0] == 0
1109DREF VLR subscr MSISDN:46071 usage decreases to: 1
1110msc_subscr_conn_is_accepted() == false
1111 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1112DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1113DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1114DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1115DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1116DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1117DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1118DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1119DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1120- MS replies with an Identity Response
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1121 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1122DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1123DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1124DMM IDENTITY RESPONSE: MI(IMEI)=423423423423420
1125DVLR set IMEI on subscriber; IMSI=901700000004620 IMEI=423423423423420
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1126DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_ID_IMEI
1127DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK
1128DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: lu_compl_vlr_new_tmsi()
1129DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
1130- sending LU Accept for MSISDN:46071, with TMSI 0x03020100
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1131DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1132DREF MSISDN:46071: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1133- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
1134 llist_count(&net->subscr_conns) == 1
1135 lu_result_sent == 1
1136msc_subscr_conn_is_accepted() == false
1137 requests shall be thwarted
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1138DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1139DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1140DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1141DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1142DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1143DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1144DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1145DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1146- MS sends TMSI Realloc Complete
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1147 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1148DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1149DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1150DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
1151DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
1152DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
1153DREF VLR subscr MSISDN:46071 usage increases to: 2
1154DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
1155DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
1156DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1157DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1158DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
1159DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
1160DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1161DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1162DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1163DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
1164DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1165DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
1166DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1167DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1168DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
1169DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
1170DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
1171DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
1172DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1173- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1174DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr84da6b12016-05-20 21:59:55 +0200[diff] [blame]1175DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
1176DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1177DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1178DRLL subscr MSISDN:46071: Freeing subscriber connection
1179DREF VLR subscr MSISDN:46071 usage decreases to: 1
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1180 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1181- LU was successful, and the conn has already been closed
1182 lu_result_sent == 1
1183 llist_count(&net->subscr_conns) == 0
1184- Subscriber has the IMEI and TMSI
1185DREF VLR subscr MSISDN:46071 usage increases to: 2
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1186 strcmp(vsub->imei, "423423423423420") == 0
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1187 vsub->tmsi == 0x03020100
1188DREF VLR subscr MSISDN:46071 usage decreases to: 1
1189---
1190- subscriber detaches
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1191 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1192 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1193DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr78ada642017-03-10 02:15:20 +0100[diff] [blame]1194DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1195DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
1196DREF VLR subscr MSISDN:46071 usage increases to: 2
1197DMM IMSI DETACH for MSISDN:46071
1198DREF VLR subscr MSISDN:46071 usage decreases to: 1
1199DREF VLR subscr MSISDN:46071 usage decreases to: 0
1200DREF freeing VLR subscr MSISDN:46071
1201DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1202- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1203DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1204DRLL Freeing subscriber connection with NULL subscriber
Philipp Maierfbf66102017-04-09 12:32:51 +0200[diff] [blame]1205 bssap_clear_sent == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1206 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1207===== test_no_authen_tmsi_imei: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1208
1209full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]1210talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]1211
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1212===== test_no_authen_imeisv
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1213- Location Update request causes an IMEISV ID request back to the MS
1214 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
1215 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1216DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1217DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1218DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1219DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1220DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1221DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1222DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1223DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1224DMM LU/new-LAC: 1/23
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1225DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1226DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1227DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1228DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1229DREF VLR subscr unknown usage increases to: 1
1230DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
1231DVLR New subscr, IMSI: 901700000004620
1232DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1233DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1234DMSC msc_tx 3 bytes to IMSI:901700000004620 via RAN_GERAN_A
1235- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051803
1236- DTAP matches expected message
1237DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMEISV
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1238DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1239DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1240- MS replies with an Identity Response, causes LU to commence with a GSUP LU request to HLR
1241 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1242DREF IMSI:901700000004620: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1243DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1244DMM IDENTITY RESPONSE: MI(IMEI-SV)=4234234234234275
1245DVLR set IMEISV on subscriber; IMSI=901700000004620 IMEISV=4234234234234275
1246DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: Received Event VLR_ULA_E_ID_IMEISV
1247DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node1()
1248DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_auth()
1249DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_ciph()
1250DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node_4()
1251DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1252DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1253DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1254DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1255DVLR GSUP tx: 04010809710000004026f0
1256GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1257DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1258DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1259DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1260 lu_result_sent == 0
1261- Subscriber has the IMEISV from the ID Response
1262DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1263 strcmp(vsub->imeisv, "4234234234234275") == 0
1264DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1265- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1266<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1267DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1268DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1269DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1270DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1271DVLR GSUP tx: 12010809710000004026f0
1272GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1273DREF VLR subscr MSISDN:46071 usage decreases to: 1
1274<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1275 lu_result_sent == 0
1276- having received subscriber data does not mean acceptance
1277msc_subscr_conn_is_accepted() == false
1278 requests shall be thwarted
1279DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1280DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1281DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1282DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1283DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1284DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1285DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1286DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1287 lu_result_sent == 0
1288- HLR also sends GSUP _UPDATE_LOCATION_RESULT
1289<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1290DVLR GSUP rx 11: 06010809710000004026f0
1291DREF VLR subscr MSISDN:46071 usage increases to: 2
1292DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1293DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1294DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1295DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1296DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1297DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
1298DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
1299DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
1300DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
1301DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
1302DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1303DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
1304DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
1305DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
1306DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
1307DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
1308DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
1309DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1310DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
1311DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
1312DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
1313DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
1314- sending LU Accept for MSISDN:46071
1315DREF VLR subscr MSISDN:46071 usage increases to: 3
1316DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
1317DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
1318DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1319DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1320DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
1321DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
1322DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
1323DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1324DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1325DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
1326DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1327DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
1328DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1329DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1330DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
1331DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
1332DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
1333DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
1334DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
1335- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1336DREF MSISDN:46071: MSC conn use - fsm == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1337DRLL subscr MSISDN:46071: Freeing subscriber connection
1338DREF VLR subscr MSISDN:46071 usage decreases to: 2
1339DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
1340DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
1341DREF VLR subscr MSISDN:46071 usage decreases to: 1
1342<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
1343- LU was successful, and the conn has already been closed
1344 lu_result_sent == 1
1345 bssap_clear_sent == 1
1346 llist_count(&net->subscr_conns) == 0
1347---
1348- subscriber detaches
1349 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
1350 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1351DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1352DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
1353DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
1354DREF VLR subscr MSISDN:46071 usage increases to: 2
1355DMM IMSI DETACH for MSISDN:46071
1356DREF VLR subscr MSISDN:46071 usage decreases to: 1
1357DREF VLR subscr MSISDN:46071 usage decreases to: 0
1358DREF freeing VLR subscr MSISDN:46071
1359DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
1360- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1361DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1362DRLL Freeing subscriber connection with NULL subscriber
1363 bssap_clear_sent == 1
1364 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1365===== test_no_authen_imeisv: SUCCESS
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1366
1367full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]1368talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1369
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1370===== test_no_authen_imeisv_imei
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1371- Location Update request causes an IMEISV ID request back to the MS
1372 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
1373 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1374DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1375DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1376DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1377DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1378DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1379DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1380DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1381DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1382DMM LU/new-LAC: 1/23
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1383DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1384DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1385DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1386DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1387DREF VLR subscr unknown usage increases to: 1
1388DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
1389DVLR New subscr, IMSI: 901700000004620
1390DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1391DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1392DMSC msc_tx 3 bytes to IMSI:901700000004620 via RAN_GERAN_A
1393- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051803
1394- DTAP matches expected message
1395DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMEISV
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1396DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1397DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1398- MS replies with an Identity Response, causes LU to commence with a GSUP LU request to HLR
1399 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1400DREF IMSI:901700000004620: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1401DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1402DMM IDENTITY RESPONSE: MI(IMEI-SV)=4234234234234275
1403DVLR set IMEISV on subscriber; IMSI=901700000004620 IMEISV=4234234234234275
1404DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: Received Event VLR_ULA_E_ID_IMEISV
1405DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node1()
1406DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_auth()
1407DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_ciph()
1408DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node_4()
1409DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1410DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1411DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1412DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1413DVLR GSUP tx: 04010809710000004026f0
1414GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1415DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1416DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1417DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1418 lu_result_sent == 0
1419- Subscriber has the IMEISV from the ID Response
1420DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1421 strcmp(vsub->imeisv, "4234234234234275") == 0
1422DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1423- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1424<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1425DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1426DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1427DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1428DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1429DVLR GSUP tx: 12010809710000004026f0
1430GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1431DREF VLR subscr MSISDN:46071 usage decreases to: 1
1432<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1433 lu_result_sent == 0
1434- having received subscriber data does not mean acceptance
1435msc_subscr_conn_is_accepted() == false
1436 requests shall be thwarted
1437DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1438DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1439DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1440DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1441DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1442DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1443DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1444DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1445 lu_result_sent == 0
1446- HLR also sends GSUP _UPDATE_LOCATION_RESULT, and we send an ID Request for the IMEI to the MS
1447<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1448DVLR GSUP rx 11: 06010809710000004026f0
1449DREF VLR subscr MSISDN:46071 usage increases to: 2
1450DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1451DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1452DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1453DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1454DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1455DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
1456DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
1457DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
1458DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
1459DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
1460DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1461DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
1462DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
1463DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
1464DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
1465DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
1466DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
1467DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1468DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
1469DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
1470DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
1471DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
1472DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI
1473DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
1474- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051802
1475- DTAP matches expected message
1476DREF VLR subscr MSISDN:46071 usage decreases to: 1
1477<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
1478- We will only do business when the IMEI is known
1479 llist_count(&net->subscr_conns) == 1
1480DREF VLR subscr MSISDN:46071 usage increases to: 2
1481 vsub->imei[0] == 0
1482DREF VLR subscr MSISDN:46071 usage decreases to: 1
1483msc_subscr_conn_is_accepted() == false
1484 requests shall be thwarted
1485DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1486DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1487DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1488DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1489DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1490DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1491DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1492DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1493- MS replies with an Identity Response
1494 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1495DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1496DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1497DMM IDENTITY RESPONSE: MI(IMEI)=423423423423420
1498DVLR set IMEI on subscriber; IMSI=901700000004620 IMEI=423423423423420
1499DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_ID_IMEI
1500DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK
1501- sending LU Accept for MSISDN:46071
1502DREF VLR subscr MSISDN:46071 usage increases to: 2
1503DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI}: state_chg to LU_COMPL_VLR_S_DONE
1504DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
1505DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1506DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1507DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
1508DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
1509DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
1510DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1511DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1512DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
1513DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1514DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
1515DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1516DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1517DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
1518DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
1519DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
1520DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
1521DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
1522- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1523DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1524DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
1525DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1526DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1527DRLL subscr MSISDN:46071: Freeing subscriber connection
1528DREF VLR subscr MSISDN:46071 usage decreases to: 1
1529 bssap_clear_sent == 1
1530- LU was successful, and the conn has already been closed
1531 lu_result_sent == 1
1532 llist_count(&net->subscr_conns) == 0
1533- Subscriber has the IMEI
1534DREF VLR subscr MSISDN:46071 usage increases to: 2
1535 strcmp(vsub->imei, "423423423423420") == 0
1536DREF VLR subscr MSISDN:46071 usage decreases to: 1
1537---
1538- subscriber detaches
1539 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
1540 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1541DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1542DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
1543DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
1544DREF VLR subscr MSISDN:46071 usage increases to: 2
1545DMM IMSI DETACH for MSISDN:46071
1546DREF VLR subscr MSISDN:46071 usage decreases to: 1
1547DREF VLR subscr MSISDN:46071 usage decreases to: 0
1548DREF freeing VLR subscr MSISDN:46071
1549DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
1550- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1551DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1552DRLL Freeing subscriber connection with NULL subscriber
1553 bssap_clear_sent == 1
1554 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1555===== test_no_authen_imeisv_imei: SUCCESS
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1556
1557full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]1558talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1559
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1560===== test_no_authen_imeisv_tmsi
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1561- Location Update request causes an IMEISV ID request back to the MS
1562 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
1563 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1564DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1565DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1566DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1567DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1568DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1569DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1570DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1571DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1572DMM LU/new-LAC: 1/23
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1573DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1574DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1575DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1576DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1577DREF VLR subscr unknown usage increases to: 1
1578DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
1579DVLR New subscr, IMSI: 901700000004620
1580DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1581DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1582DMSC msc_tx 3 bytes to IMSI:901700000004620 via RAN_GERAN_A
1583- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051803
1584- DTAP matches expected message
1585DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMEISV
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1586DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1587DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1588- MS replies with an Identity Response, causes LU to commence with a GSUP LU request to HLR
1589 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1590DREF IMSI:901700000004620: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1591DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1592DMM IDENTITY RESPONSE: MI(IMEI-SV)=4234234234234275
1593DVLR set IMEISV on subscriber; IMSI=901700000004620 IMEISV=4234234234234275
1594DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: Received Event VLR_ULA_E_ID_IMEISV
1595DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node1()
1596DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_auth()
1597DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_ciph()
1598DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node_4()
1599DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1600DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1601DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1602DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1603DVLR GSUP tx: 04010809710000004026f0
1604GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1605DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1606DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1607DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1608 lu_result_sent == 0
1609- Subscriber has the IMEISV from the ID Response
1610DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1611 strcmp(vsub->imeisv, "4234234234234275") == 0
1612DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1613- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1614<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1615DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1616DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1617DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1618DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1619DVLR GSUP tx: 12010809710000004026f0
1620GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1621DREF VLR subscr MSISDN:46071 usage decreases to: 1
1622<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1623 lu_result_sent == 0
1624- having received subscriber data does not mean acceptance
1625msc_subscr_conn_is_accepted() == false
1626 requests shall be thwarted
1627DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1628DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1629DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1630DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1631DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1632DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1633DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1634DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1635 lu_result_sent == 0
1636- HLR also sends GSUP _UPDATE_LOCATION_RESULT
1637<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1638DVLR GSUP rx 11: 06010809710000004026f0
1639DREF VLR subscr MSISDN:46071 usage increases to: 2
1640DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1641DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1642DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1643DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1644DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1645DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
1646DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
1647DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
1648DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
1649DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
1650DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1651DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
1652DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
1653DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
1654DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
1655DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
1656DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
1657DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1658DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
1659DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
1660DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
1661DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
1662DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
1663DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
1664- sending LU Accept for MSISDN:46071, with TMSI 0x03020100
1665DREF VLR subscr MSISDN:46071 usage decreases to: 1
1666<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
1667- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
1668 llist_count(&net->subscr_conns) == 1
1669 lu_result_sent == 1
1670msc_subscr_conn_is_accepted() == false
1671 requests shall be thwarted
1672DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1673DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1674DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1675DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1676DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1677DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1678DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1679DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1680- even though the TMSI is not acked, we can already find the subscr with it
1681DREF VLR subscr MSISDN:46071 usage increases to: 2
1682 vsub != NULL == 1
1683 strcmp(vsub->imsi, imsi) == 0
1684 vsub->tmsi_new == 0x03020100
1685 vsub->tmsi == 0xffffffff
1686DREF VLR subscr MSISDN:46071 usage decreases to: 1
1687- MS sends TMSI Realloc Complete
1688 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1689DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1690DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
1691DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
1692DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
1693DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
1694DREF VLR subscr MSISDN:46071 usage increases to: 2
1695DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
1696DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
1697DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1698DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1699DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
1700DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
1701DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
1702DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1703DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1704DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
1705DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1706DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
1707DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1708DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1709DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
1710DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
1711DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
1712DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
1713DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
1714- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1715DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1716DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
1717DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1718DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1719DRLL subscr MSISDN:46071: Freeing subscriber connection
1720DREF VLR subscr MSISDN:46071 usage decreases to: 1
1721 bssap_clear_sent == 1
1722- LU was successful, and the conn has already been closed
1723 llist_count(&net->subscr_conns) == 0
1724---
1725- subscriber sends LU Request, this time with the TMSI
1726- Location Update request causes an IMEISV ID request back to the MS
1727 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
1728 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1729DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1730DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1731DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1732DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1733DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1734DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1735DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1736DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1737DMM LU/new-LAC: 1/23
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1738DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1739DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1740DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1741DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1742DREF VLR subscr MSISDN:46071 usage increases to: 2
1743DREF VLR subscr MSISDN:46071 usage increases to: 3
1744DREF VLR subscr MSISDN:46071 usage decreases to: 2
1745DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
1746- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051803
1747- DTAP matches expected message
1748DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMEISV
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1749DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1750DREF MSISDN:46071: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1751- MS replies with an Identity Response, causes LU to commence with a GSUP LU request to HLR
1752 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1753DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1754DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1755DMM IDENTITY RESPONSE: MI(IMEI-SV)=5234234234234276
1756DVLR set IMEISV on subscriber; IMSI=901700000004620 IMEISV=5234234234234276
1757DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: Received Event VLR_ULA_E_ID_IMEISV
1758DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node1()
1759DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_auth()
1760DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_ciph()
1761DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node_4()
1762DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1763DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1764DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1765DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1766DVLR GSUP tx: 04010809710000004026f0
1767GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1768DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1769DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1770DREF MSISDN:46071: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1771 lu_result_sent == 0
1772- Subscriber has the IMEISV from the ID Response
1773DREF VLR subscr MSISDN:46071 usage increases to: 3
1774 strcmp(vsub->imeisv, "5234234234234276") == 0
1775DREF VLR subscr MSISDN:46071 usage decreases to: 2
1776- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1777<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1778DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1779DREF VLR subscr MSISDN:46071 usage increases to: 3
1780DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1781DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=3)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1782DVLR GSUP tx: 12010809710000004026f0
1783GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1784DREF VLR subscr MSISDN:46071 usage decreases to: 2
1785<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1786 lu_result_sent == 0
1787- having received subscriber data does not mean acceptance
1788msc_subscr_conn_is_accepted() == false
1789 requests shall be thwarted
1790DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1791DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1792DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1793DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1794DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1795DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1796DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1797DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1798 lu_result_sent == 0
1799- HLR also sends GSUP _UPDATE_LOCATION_RESULT
1800<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1801DVLR GSUP rx 11: 06010809710000004026f0
1802DREF VLR subscr MSISDN:46071 usage increases to: 3
1803DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1804DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1805DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1806DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1807DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1808DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
1809DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
1810DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
1811DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
1812DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
1813DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1814DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
1815DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
1816DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
1817DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
1818DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
1819DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
1820DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1821DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
1822DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
1823DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
1824DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
1825DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
1826DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
1827- sending LU Accept for MSISDN:46071, with TMSI 0x07060504
1828DREF VLR subscr MSISDN:46071 usage decreases to: 2
1829<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
1830- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
1831 llist_count(&net->subscr_conns) == 1
1832 lu_result_sent == 1
1833msc_subscr_conn_is_accepted() == false
1834 requests shall be thwarted
1835DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1836DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1837DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1838DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1839DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1840DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1841DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1842DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1843- even though the TMSI is not acked, we can already find the subscr with it
1844DREF VLR subscr MSISDN:46071 usage increases to: 3
1845 vsub != NULL == 1
1846 strcmp(vsub->imsi, imsi) == 0
1847 vsub->tmsi_new == 0x07060504
1848 vsub->tmsi == 0x03020100
1849DREF VLR subscr MSISDN:46071 usage decreases to: 2
1850- MS sends TMSI Realloc Complete
1851 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1852DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1853DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
1854DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
1855DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
1856DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
1857DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
1858DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
1859DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1860DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
1861DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
1862DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
1863DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
1864DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1865DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1866DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
1867DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1868DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
1869DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
1870DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
1871DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
1872DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
1873DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
1874DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
1875DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
1876- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1877DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1878DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
1879DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1880DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1881DRLL subscr MSISDN:46071: Freeing subscriber connection
1882DREF VLR subscr MSISDN:46071 usage decreases to: 1
1883 bssap_clear_sent == 1
1884- LU was successful, and the conn has already been closed
1885 llist_count(&net->subscr_conns) == 0
1886- subscriber has the new TMSI
1887DREF VLR subscr MSISDN:46071 usage increases to: 2
1888 vsub != NULL == 1
1889 strcmp(vsub->imsi, imsi) == 0
1890 vsub->tmsi_new == 0xffffffff
1891 vsub->tmsi == 0x07060504
1892DREF VLR subscr MSISDN:46071 usage decreases to: 1
1893---
1894- subscriber detaches, using new TMSI
1895 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
1896 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1897DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1898DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
1899DMM IMSI DETACH INDICATION: MI(TMSI)=117835012
1900DREF VLR subscr MSISDN:46071 usage increases to: 2
1901DMM IMSI DETACH for MSISDN:46071
1902DREF VLR subscr MSISDN:46071 usage decreases to: 1
1903DREF VLR subscr MSISDN:46071 usage decreases to: 0
1904DREF freeing VLR subscr MSISDN:46071
1905DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
1906- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1907DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1908DRLL Freeing subscriber connection with NULL subscriber
1909 bssap_clear_sent == 1
1910 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1911===== test_no_authen_imeisv_tmsi: SUCCESS
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1912
1913full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]1914talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1915
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]1916===== test_no_authen_imeisv_tmsi_imei
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1917- Location Update request causes an IMEISV ID request back to the MS
1918 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
1919 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1920DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1921DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1922DREF unknown: MSC conn use + fsm == 2 (0x5)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1923DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Allocated
1924DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
1925DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Neels Hofmeyr16c42b52018-04-02 12:26:16 +0200[diff] [blame]1926DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Updated ID from LU
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1927DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
Neels Hofmeyr8a656eb2017-11-22 02:55:52 +0100[diff] [blame]1928DMM LU/new-LAC: 1/23
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1929DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Allocated
1930DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000004620)
1931DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
1932DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
1933DREF VLR subscr unknown usage increases to: 1
1934DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
1935DVLR New subscr, IMSI: 901700000004620
1936DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1937DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1938DMSC msc_tx 3 bytes to IMSI:901700000004620 via RAN_GERAN_A
1939- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051803
1940- DTAP matches expected message
1941DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMEISV
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1942DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1943DREF IMSI:901700000004620: MSC conn use - compl_l3 == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1944- MS replies with an Identity Response, causes LU to commence with a GSUP LU request to HLR
1945 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1946DREF IMSI:901700000004620: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1947DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
1948DMM IDENTITY RESPONSE: MI(IMEI-SV)=4234234234234275
1949DVLR set IMEISV on subscriber; IMSI=901700000004620 IMEISV=4234234234234275
1950DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: Received Event VLR_ULA_E_ID_IMEISV
1951DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node1()
1952DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_auth()
1953DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_post_ciph()
1954DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: vlr_loc_upd_node_4()
1955DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_IMEISV}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
1956DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
1957DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
1958DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
1959DVLR GSUP tx: 04010809710000004026f0
1960GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
1961DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]1962DMM IMSI:901700000004620: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]1963DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1964 lu_result_sent == 0
1965- Subscriber has the IMEISV from the ID Response
1966DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1967 strcmp(vsub->imeisv, "4234234234234275") == 0
1968DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
1969- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
1970<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1
1971DVLR GSUP rx 17: 10010809710000004026f00804036470f1
1972DREF VLR subscr IMSI:901700000004620 usage increases to: 2
1973DVLR IMSI:901700000004620 has MSISDN:46071
Maxa263bb22017-12-27 13:23:44 +0100[diff] [blame]1974DVLR SUBSCR(MSISDN:46071) VLR: update for IMSI=901700000004620 (MSISDN=46071, used=2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1975DVLR GSUP tx: 12010809710000004026f0
1976GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
1977DREF VLR subscr MSISDN:46071 usage decreases to: 1
1978<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
1979 lu_result_sent == 0
1980- having received subscriber data does not mean acceptance
1981msc_subscr_conn_is_accepted() == false
1982 requests shall be thwarted
1983DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
1984DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
1985DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
1986DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
1987DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
1988DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]1989DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
1990DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]1991 lu_result_sent == 0
1992- HLR also sends GSUP _UPDATE_LOCATION_RESULT, and we send an ID Request for the IMEI to the MS
1993<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
1994DVLR GSUP rx 11: 06010809710000004026f0
1995DREF VLR subscr MSISDN:46071 usage increases to: 2
1996DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
1997DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
1998DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
1999DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
2000DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
2001DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
2002DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
2003DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
2004DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
2005DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
2006DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000004620)
2007DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
2008DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
2009DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
2010DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000004620)
2011DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
2012DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
2013DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
2014DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000004620)
2015DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
2016DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
2017DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
2018DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI_TMSI
2019DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
2020- DTAP --RAN_GERAN_A--> MS: GSM48_MT_MM_ID_REQ: 051802
2021- DTAP matches expected message
2022DREF VLR subscr MSISDN:46071 usage decreases to: 1
2023<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
2024- We will only do business when the IMEI is known
2025 llist_count(&net->subscr_conns) == 1
2026DREF VLR subscr MSISDN:46071 usage increases to: 2
2027 vsub->imei[0] == 0
2028DREF VLR subscr MSISDN:46071 usage decreases to: 1
2029msc_subscr_conn_is_accepted() == false
2030 requests shall be thwarted
2031DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
2032DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
2033DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
2034DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
2035DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
2036DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]2037DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
2038DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2039- MS replies with an Identity Response
2040 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_ID_RESP
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2041DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2042DRLL Dispatching 04.08 message GSM48_MT_MM_ID_RESP (0x5:0x19)
2043DMM IDENTITY RESPONSE: MI(IMEI)=423423423423420
2044DVLR set IMEI on subscriber; IMSI=901700000004620 IMEI=423423423423420
2045DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_ID_IMEI
2046DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK
2047DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: lu_compl_vlr_new_tmsi()
2048DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
2049- sending LU Accept for MSISDN:46071, with TMSI 0x03020100
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]2050DMM MSISDN:46071: subscr_conn_release_when_unused: conn still being established (SUBSCR_CONN_S_NEW)
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2051DREF MSISDN:46071: MSC conn use - dtap == 1 (0x4)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2052- a LU Accept with a new TMSI was sent, waiting for TMSI Realloc Compl
2053 llist_count(&net->subscr_conns) == 1
2054 lu_result_sent == 1
2055msc_subscr_conn_is_accepted() == false
2056 requests shall be thwarted
2057DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
2058DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_CC_SETUP
2059DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
2060DRLL subscr MSISDN:46071: Message not permitted for initial conn: unknown 0x33
2061DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
2062DRLL subscr MSISDN:46071: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
Harald Welte80315ef2018-01-24 22:53:00 +0100[diff] [blame]2063DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
2064DRLL subscr MSISDN:46071: Message not permitted for initial conn: SMS:0x01
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2065- MS sends TMSI Realloc Complete
2066 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_TMSI_REALL_COMPL
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2067DREF MSISDN:46071: MSC conn use + dtap == 2 (0x6)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2068DRLL Dispatching 04.08 message GSM48_MT_MM_TMSI_REALL_COMPL (0x5:0x1b)
2069DMM TMSI Reallocation Completed. Subscriber: MSISDN:46071
2070DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
2071DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
2072DREF VLR subscr MSISDN:46071 usage increases to: 2
2073DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
2074DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
2075DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
2076DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000004620)
2077DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
2078DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
2079DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
2080DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2081DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Neels Hofmeyre9e2f5c2018-03-15 13:26:43 +0100[diff] [blame]2082DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_RELEASE_WHEN_UNUSED
2083DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_release_when_unused: releasing conn
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2084DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
2085DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
2086DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
2087DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
2088DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
2089DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
2090DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
2091DMM msc_subscr_conn_close(vsub=MSISDN:46071, cause=2): no conn fsm, releasing directly without release event.
2092- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2093DREF MSISDN:46071: MSC conn use - fsm == 1 (0x2)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2094DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
2095DMM Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2096DREF MSISDN:46071: MSC conn use - dtap == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2097DRLL subscr MSISDN:46071: Freeing subscriber connection
2098DREF VLR subscr MSISDN:46071 usage decreases to: 1
2099 bssap_clear_sent == 1
2100- LU was successful, and the conn has already been closed
2101 lu_result_sent == 1
2102 llist_count(&net->subscr_conns) == 0
2103- Subscriber has the IMEISV, IMEI and TMSI
2104DREF VLR subscr MSISDN:46071 usage increases to: 2
2105 strcmp(vsub->imeisv, "4234234234234275") == 0
2106 strcmp(vsub->imei, "423423423423420") == 0
2107 vsub->tmsi == 0x03020100
2108DREF VLR subscr MSISDN:46071 usage decreases to: 1
2109---
2110- subscriber detaches
2111 MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
2112 new conn
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2113DREF unknown: MSC conn use + compl_l3 == 1 (0x1)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2114DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
2115DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
2116DREF VLR subscr MSISDN:46071 usage increases to: 2
2117DMM IMSI DETACH for MSISDN:46071
2118DREF VLR subscr MSISDN:46071 usage decreases to: 1
2119DREF VLR subscr MSISDN:46071 usage decreases to: 0
2120DREF freeing VLR subscr MSISDN:46071
2121DMM msc_subscr_conn_close(vsub=unknown, cause=0): no conn fsm, releasing directly without release event.
2122- BSSAP Clear --RAN_GERAN_A--> MS
Neels Hofmeyr6166f292017-11-22 14:33:12 +0100[diff] [blame]2123DREF unknown: MSC conn use - compl_l3 == 0 (0x0)
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2124DRLL Freeing subscriber connection with NULL subscriber
2125 bssap_clear_sent == 1
2126 llist_count(&net->subscr_conns) == 0
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]2127===== test_no_authen_imeisv_tmsi_imei: SUCCESS
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2128
2129full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]2130talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr34d33bd2017-07-20 02:56:21 +0200[diff] [blame]2131
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]2132full talloc report on 'msgb' (total 0 bytes in 1 blocks)
Neels Hofmeyr08b38282018-03-30 23:04:04 +0200[diff] [blame]2133talloc_total_blocks(tall_bsc_ctx) == 12
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]2134