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