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