Gitiles
Code Review Sign In
gerrit.osmocom.org / osmo-msc / 42ac3665c8e179a3a33a25da9aeff6df385bdc06 / . / tests / msc_vlr / msc_vlr_test_hlr_timeout.err
blob: 15873224750e8c83420d0830ad609319ca30f871 [file] [log] [blame]
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]1DLMGCP MGCP client: using endpoint domain '@mgw'
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]2===== test_hlr_timeout_lu_auth_info
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]3- Total time passed: 0.000000 s
4- Location Update request causes a GSUP Send Auth Info request to HLR
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]5 MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]6 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]7DMSC msub_fsm{active}: Allocated
8DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
9DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
10DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
11DMSC dummy_msc_i{0}: Allocated
12DMSC dummy_msc_i{0}: is child of msub_fsm
13DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
14DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
15DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
16DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
17DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
18DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + mm_rx_loc_upd_req: now used by 2 (rx_from_ms,mm_rx_loc_upd_req)
19DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + lu: now used by 3 (rx_from_ms,mm_rx_loc_upd_req,lu)
20DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
21DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
22DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
23DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]24DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]25DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
26DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]27DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
28DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
29DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
30DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol1086e202021-07-02 18:36:32 +0200[diff] [blame]31DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smithcbf2c932019-05-06 13:09:55 +0200[diff] [blame]32DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]33DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
34DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
35DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Allocated
36DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
37DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
Neels Hofmeyr63b24642019-12-12 01:31:04 +0100[diff] [blame]38GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f02801020a0101
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]39DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
40DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - mm_rx_loc_upd_req: now used by 2 (rx_from_ms,lu)
41DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]42 lu_result_sent == 0
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]43
44
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]45- HLR never replies
46- At first, we're still waiting
47- Total time passed: 0.000423 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]48 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]49- Total time passed: 1.000658 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]50 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]51- Total time passed: 2.000893 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]52 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]53- Total time passed: 3.001128 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]54 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]55- Total time passed: 4.001363 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]56 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]57- Total time passed: 5.001598 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]58DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Timeout of X1
59DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_CN_CLOSE
60DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - lu: now used by 0 (-)
61DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_UNUSED
62DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_RELEASING
63DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
64DREF VLR subscr IMSI-901700000004620 + msc_a_fsm_releasing_onenter: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
65DREF VLR subscr IMSI-901700000004620 + vlr_subscr_cancel_attach_fsm: now used by 3 (active-conn,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
66- sending LU Reject for IMSI-901700000004620:GERAN-A:LU, cause 22
67DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE
68DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_CN_CLOSE
69DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Event MSC_A_EV_CN_CLOSE not permitted
70DREF VLR subscr IMSI-901700000004620 - vlr_subscr_cancel_attach_fsm: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
71DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
72DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
73DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
74DREF VLR subscr IMSI-901700000004620 - msc_a_fsm_releasing_onenter: now used by 1 (active-conn)
Neels Hofmeyrc036b792018-11-29 22:37:51 +0100[diff] [blame]75- RAN_CONN_TIMEOUT has passed, conn is gone.
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200[diff] [blame]76 bssap_clear_sent == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]77DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
78DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
79DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
80DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
81DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
82DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
83DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
84DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
85DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
86DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
87DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:GERAN-A:LU)
88DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
89DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
90DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
91DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
92DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
93DMSC msub(IMSI-901700000004620) MSC-A terminated
94DMSC msub(IMSI-901700000004620) 1 MSC-I still active
95DMSC msub_fsm{active}: state_chg to terminating
96DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
97DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
98DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Removing from parent msub_fsm
99DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
100DMSC msub(IMSI-901700000004620) Free
101DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-)
102DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3)
103DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
104DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
105- msub gone
106 llist_count(&msub_list) == 0
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]107 lu_result_sent == 2
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]108===== test_hlr_timeout_lu_auth_info: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]109
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]110===== test_hlr_timeout_lu_upd_loc_result
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]111- Total time passed: 0.000000 s
112- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr7814a832018-12-26 00:40:18 +0100[diff] [blame]113 MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]114 new conn
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]115DMSC msub_fsm{active}: Allocated
116DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
117DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
118DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
119DMSC dummy_msc_i{0}: Allocated
120DMSC dummy_msc_i{0}: is child of msub_fsm
121DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
122DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
123DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
124DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
125DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
126DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + mm_rx_loc_upd_req: now used by 2 (rx_from_ms,mm_rx_loc_upd_req)
127DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: + lu: now used by 3 (rx_from_ms,mm_rx_loc_upd_req,lu)
128DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
129DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
130DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
131DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]132DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]133DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
134DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]135DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
136DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
137DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
138DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol1086e202021-07-02 18:36:32 +0200[diff] [blame]139DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smithcbf2c932019-05-06 13:09:55 +0200[diff] [blame]140DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]141DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
142DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
143DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
Harald Welte544a32f2020-06-21 22:15:53 +0200[diff] [blame]144DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN encode: COMMON_ID on GERAN-A
145DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]146DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
147DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
148DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Allocated
149DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
150DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
151GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f02801020a0101
152DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
153DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - mm_rx_loc_upd_req: now used by 2 (rx_from_ms,lu)
154DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]155 lu_result_sent == 0
156- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]157<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101
158DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]159DVLR IMSI:901700000004620 has MSISDN:46071
Neels Hofmeyr7c5346c2019-02-19 02:36:35 +0100[diff] [blame]160DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071)
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]161GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101
162DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]163<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
164 lu_result_sent == 0
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]165
166
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]167- HLR never sends GSUP _UPDATE_LOCATION_RESULT
168- At first, we're still waiting
169- Total time passed: 0.000423 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]170 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]171 lu_result_sent == 0
172- Total time passed: 1.000658 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]173 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]174 lu_result_sent == 0
175- Total time passed: 2.000893 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]176 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]177 lu_result_sent == 0
178- Total time passed: 3.001128 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]179 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]180 lu_result_sent == 0
181- Total time passed: 4.001363 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]182 llist_count(&msub_list) == 1
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]183 lu_result_sent == 0
184- Total time passed: 5.001598 s
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]185DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Timeout of X1
186DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_CN_CLOSE
187DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - lu: now used by 0 (-)
188DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_UNUSED
189DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_RELEASING
190DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
191DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
192DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 3 (active-conn,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
193- sending LU Reject for IMSI-901700000004620:MSISDN-46071:GERAN-A:LU, cause 22
194DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_DONE
195DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_CN_CLOSE
196DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Event MSC_A_EV_CN_CLOSE not permitted
197DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
198DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
199DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
200DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
201DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 1 (active-conn)
Neels Hofmeyrc036b792018-11-29 22:37:51 +0100[diff] [blame]202- RAN_CONN_TIMEOUT has passed, conn is gone.
Neels Hofmeyr4068ab22018-04-01 20:55:54 +0200[diff] [blame]203 bssap_clear_sent == 1
Neels Hofmeyrc4628a32018-12-07 14:47:34 +0100[diff] [blame]204DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
205DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
206DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
207DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
208DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
209DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
210DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
211DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
212DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
213DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
214DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
215DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
216DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
217DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
218DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
219DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
220DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
221DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
222DMSC msub_fsm{active}: state_chg to terminating
223DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
224DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
225DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Removing from parent msub_fsm
226DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
227DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
228DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-)
229DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 3)
230DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
231DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
232- msub gone
233 llist_count(&msub_list) == 0
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]234 lu_result_sent == 2
Neels Hofmeyrdfdc61d2018-03-02 00:40:58 +0100[diff] [blame]235===== test_hlr_timeout_lu_upd_loc_result: SUCCESS
Neels Hofmeyr6a29d322017-01-25 15:04:16 +0100[diff] [blame]236