Blame - tests/msc_vlr/msc_vlr_test_ms_timeout.err - osmo-msc

blob: c4a73e35bc1219d4ddba5953b40c0587b1a9f85a [file] [log] [blame]

Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	1	===== test_ms_timeout_lu_auth_resp
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	2	- Total time passed: 0.000000 s
				3	- Location Update request causes a GSUP Send Auth Info request to HLR
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	4	MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	5	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	6	DMSC msub_fsm{active}: Allocated
				7	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				8	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				9	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				10	DMSC dummy_msc_i{0}: Allocated
				11	DMSC dummy_msc_i{0}: is child of msub_fsm
				12	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				13	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				14	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
				15	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
				16	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
				17	DREF 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)
				18	DREF 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)
				19	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
				20	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
				21	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
				22	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	23	DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	24	DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
				25	DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	26	DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
				27	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
				28	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
				29	DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol	1086e20	2021-07-02 18:36:32 +0200	[diff] [blame]	30	DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smith	cbf2c93	2019-05-06 13:09:55 +0200	[diff] [blame]	31	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	32	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
				33	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
				34	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Allocated
				35	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
				36	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
Neels Hofmeyr	63b2464	2019-12-12 01:31:04 +0100	[diff] [blame]	37	GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f02801020a0101
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	38	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
				39	DREF 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)
				40	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	41	lu_result_sent == 0
				42	- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	43	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000a0101
				44	DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
				45	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	46	DVLR SUBSCR(IMSI-901700000004620) Received 1 auth tuples
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	47	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP
				48	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
				49	- sending GSM Auth Request for IMSI-901700000004620:GERAN-A:LU: tuple use_count=1 key_seq=0 auth_types=0x1 and...
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	50	- ...rand=585df1ae287f6e273dce07090d61320b
				51	- ...expecting sres=2d8b2c3e
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	52	DREF VLR subscr IMSI-901700000004620 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	53	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0
				54	auth_request_sent == 1
				55	lu_result_sent == 0
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	56
				57
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	58	- MS fails to send an Authentication Response
				59	- At first, we're still waiting
				60	- Total time passed: 0.000423 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	61	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	62	lu_result_sent == 0
				63	- Total time passed: 1.000658 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	64	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	65	lu_result_sent == 0
				66	- Total time passed: 2.000893 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	67	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	68	lu_result_sent == 0
				69	- Total time passed: 3.001128 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	70	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	71	lu_result_sent == 0
				72	- Total time passed: 4.001363 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	73	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	74	lu_result_sent == 0
				75	- Total time passed: 5.001598 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	76	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Timeout of X1
				77	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_CN_CLOSE
				78	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - lu: now used by 0 (-)
				79	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_UNUSED
				80	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_RELEASING
				81	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
				82	DREF VLR subscr IMSI-901700000004620 + msc_a_fsm_releasing_onenter: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				83	DREF 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)
				84	- sending LU Reject for IMSI-901700000004620:GERAN-A:LU, cause 22
				85	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE
				86	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_CN_CLOSE
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	87	DREF VLR subscr IMSI-901700000004620 - vlr_subscr_cancel_attach_fsm: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				88	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
				89	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				90	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				91	DREF VLR subscr IMSI-901700000004620 - msc_a_fsm_releasing_onenter: now used by 1 (active-conn)
Neels Hofmeyr	c036b79	2018-11-29 22:37:51 +0100	[diff] [blame]	92	- RAN_CONN_TIMEOUT has passed, conn is gone.
Neels Hofmeyr	4068ab2	2018-04-01 20:55:54 +0200	[diff] [blame]	93	bssap_clear_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	94	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				95	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				96	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				97	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				98	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				99	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				100	DVLR 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))
				101	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
				102	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
				103	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				104	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:GERAN-A:LU)
				105	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
				106	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				107	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				108	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
				109	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				110	DMSC msub(IMSI-901700000004620) MSC-A terminated
				111	DMSC msub(IMSI-901700000004620) 1 MSC-I still active
				112	DMSC msub_fsm{active}: state_chg to terminating
				113	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
				114	DMSC 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))
				115	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Removing from parent msub_fsm
				116	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				117	DMSC msub(IMSI-901700000004620) Free
				118	DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-)
				119	DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3)
				120	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				121	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				122	- msub gone
				123	llist_count(&msub_list) == 0
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	124	lu_result_sent == 2
Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	125	===== test_ms_timeout_lu_auth_resp: SUCCESS
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	126
Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	127	===== test_ms_timeout_cm_auth_resp
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	128	- Total time passed: 0.000000 s
				129	- Location Update request causes a GSUP Send Auth Info request to HLR
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	130	MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	131	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	132	DMSC msub_fsm{active}: Allocated
				133	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				134	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				135	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				136	DMSC dummy_msc_i{0}: Allocated
				137	DMSC dummy_msc_i{0}: is child of msub_fsm
				138	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				139	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				140	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
				141	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
				142	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
				143	DREF 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)
				144	DREF 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)
				145	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
				146	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
				147	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
				148	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	149	DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	150	DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
				151	DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	152	DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
				153	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
				154	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
				155	DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol	1086e20	2021-07-02 18:36:32 +0200	[diff] [blame]	156	DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smith	cbf2c93	2019-05-06 13:09:55 +0200	[diff] [blame]	157	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	158	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
				159	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
				160	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Allocated
				161	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
				162	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
Neels Hofmeyr	63b2464	2019-12-12 01:31:04 +0100	[diff] [blame]	163	GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f02801020a0101
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	164	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
				165	DREF 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)
				166	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	167	lu_result_sent == 0
				168	- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	169	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d70000a0101
				170	DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
				171	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	172	DVLR SUBSCR(IMSI-901700000004620) Received 5 auth tuples
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	173	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP
				174	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
				175	- sending GSM Auth Request for IMSI-901700000004620:GERAN-A:LU: tuple use_count=1 key_seq=0 auth_types=0x1 and...
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	176	- ...rand=585df1ae287f6e273dce07090d61320b
				177	- ...expecting sres=2d8b2c3e
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	178	DREF VLR subscr IMSI-901700000004620 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	179	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0
				180	auth_request_sent == 1
				181	lu_result_sent == 0
				182	- MS sends Authen Response, VLR accepts and sends GSUP LU Req to HLR
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	183	MSC <--GERAN-A-- MS: GSM48_MT_MM_AUTH_RESP
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	184	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: + rx_from_ms: now used by 2 (lu,rx_from_ms)
				185	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN decode: DTAP
				186	DRLL msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Dispatching 04.08 message: MM GSM48_MT_MM_AUTH_RESP
				187	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: MM GSM AUTHENTICATION RESPONSE (sres = 2d8b2c3e)
				188	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	189	DVLR SUBSCR(IMSI-901700000004620) AUTH on GERAN received SRES/RES: 2d8b2c3e (4 bytes)
				190	DVLR SUBSCR(IMSI-901700000004620) AUTH established GSM security context
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	191	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
				192	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
				193	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				194	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
Neels Hofmeyr	3189f39	2022-10-26 18:11:58 +0200	[diff] [blame]	195	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_SUCCESS
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	196	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
				197	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph()
Harald Welte	544a32f	2020-06-21 22:15:53 +0200	[diff] [blame]	198	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN encode: COMMON_ID on GERAN-A
				199	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	200	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4()
				201	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
				202	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Allocated
				203	DVLR 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)
				204	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
				205	GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f02801020a0101
				206	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
				207	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Deallocated
				208	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	209	lu_result_sent == 0
				210	- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	211	<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101
				212	DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	213	DVLR IMSI:901700000004620 has MSISDN:46071
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	214	DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071)
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	215	GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101
				216	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	217	<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
				218	lu_result_sent == 0
				219	- HLR also sends GSUP _UPDATE_LOCATION_RESULT
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	220	<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f00a0101
				221	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
				222	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
				223	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
				224	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
				225	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				226	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				227	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
				228	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
				229	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Allocated
				230	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				231	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
				232	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
				233	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
				234	- sending LU Accept for IMSI-901700000004620:MSISDN-46071:GERAN-A:LU
				235	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + attached: now used by 3 (active-conn,vlr_gsup_rx,attached)
				236	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
				237	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
				238	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU))
				239	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				240	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU)
				241	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
				242	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
				243	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
				244	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: - lu: now used by 0 (-)
				245	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_UNUSED
				246	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_RELEASING
				247	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
				248	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
				249	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 5 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
				250	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
				251	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
				252	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				253	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				254	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 3 (active-conn,vlr_gsup_rx,attached)
				255	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
				256	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (active-conn,attached)
Neels Hofmeyr	4068ab2	2018-04-01 20:55:54 +0200	[diff] [blame]	257	<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
				258	bssap_clear_sent == 1
				259	- LU was successful, and the conn has already been closed
				260	lu_result_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	261	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				262	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				263	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				264	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				265	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				266	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				267	DVLR 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))
				268	DVLR 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)
				269	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
				270	DVLR 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)
				271	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				272	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
				273	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				274	DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
				275	DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
				276	DMSC msub_fsm{active}: state_chg to terminating
				277	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
				278	DMSC 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))
				279	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Removing from parent msub_fsm
				280	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				281	DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
				282	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 1 (attached)
				283	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				284	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				285	- msub gone
				286	llist_count(&msub_list) == 0
				287
				288
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	289	- after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	290	MSC <--GERAN-A-- MS: GSM48_MT_MM_CM_SERV_REQ
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	291	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	292	DMSC msub_fsm{active}: Allocated
				293	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				294	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				295	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				296	DMSC dummy_msc_i{0}: Allocated
				297	DMSC dummy_msc_i{0}: is child of msub_fsm
				298	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				299	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				300	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_CM_SERV_REQ
				301	DMM msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: Rx CM SERVICE REQUEST cm_service_type=Short-Messaging-Service
				302	DREF msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: + cm_service_sms: now used by 2 (rx_from_ms,cm_service_sms)
				303	DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: Allocated
				304	DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: is child of msc_a(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ)
				305	DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
				306	DVLR Process_Access_Request_VLR(IMSI-901700000004620:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	307	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + proc_arq_vlr_fn_init: now used by 2 (attached,proc_arq_vlr_fn_init)
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	308	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + active-conn: now used by 3 (attached,proc_arq_vlr_fn_init,active-conn)
				309	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
				310	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
				311	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
				312	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
				313	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_NEEDS_AUTH}: Allocated
				314	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				315	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
				316	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP
				317	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
				318	- sending GSM Auth Request for IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ: tuple use_count=1 key_seq=1 auth_types=0x1 and...
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	319	- ...rand=12aca96fb4ffdea5c985cbafa9b6e18b
				320	- ...expecting sres=20bde240
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	321	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - proc_arq_vlr_fn_init: now used by 2 (attached,active-conn)
				322	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (cm_service_sms)
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	323	cm_service_result_sent == 0
				324	auth_request_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	325
				326
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	327	- MS fails to send an Authentication Response
				328	- At first, we're still waiting
				329	- Total time passed: 0.000423 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	330	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	331	cm_service_result_sent == 0
				332	- Total time passed: 1.000658 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	333	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	334	cm_service_result_sent == 0
				335	- Total time passed: 2.000893 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	336	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	337	cm_service_result_sent == 0
				338	- Total time passed: 3.001128 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	339	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	340	cm_service_result_sent == 0
				341	- Total time passed: 4.001363 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	342	llist_count(&msub_list) == 1
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	343	cm_service_result_sent == 0
				344	- Total time passed: 5.001598 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	345	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: Timeout of X1
				346	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_CN_CLOSE
				347	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_RELEASING
				348	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Releasing: msc_a use is 1 (cm_service_sms)
				349	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 3 (attached,active-conn,msc_a_fsm_releasing_onenter)
				350	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 4 (attached,active-conn,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
				351	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_WAIT_AUTH}: Cancel: OSMO_FSM_TERM_ERROR
				352	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(CONGESTION)
				353	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_DONE
				354	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Process Access Request result: CONGESTION
				355	- sending CM Service Reject (Short-Messaging-Service) for IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ, cause: CONGESTION
				356	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_CN_CLOSE
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	357	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 3 (attached,active-conn,msc_a_fsm_releasing_onenter)
				358	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Releasing: canceling still pending use: cm_service_sms (1)
				359	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: - cm_service_sms: now used by 0 (-)
				360	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				361	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
				362	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				363	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				364	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 2 (attached,active-conn)
Neels Hofmeyr	c036b79	2018-11-29 22:37:51 +0100	[diff] [blame]	365	- RAN_CONN_TIMEOUT has passed, conn is gone.
Neels Hofmeyr	4068ab2	2018-04-01 20:55:54 +0200	[diff] [blame]	366	bssap_clear_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	367	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				368	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				369	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				370	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				371	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				372	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				373	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
				374	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_WAIT_RESP}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
				375	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_WAIT_RESP}: Removing from parent Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				376	DVLR VLR_Authenticate(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){VLR_SUB_AS_WAIT_RESP}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				377	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				378	DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				379	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				380	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: max total use count was 2
				381	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				382	DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
				383	DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
				384	DMSC msub_fsm{active}: state_chg to terminating
				385	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
				386	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ))
				387	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Removing from parent msub_fsm
				388	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				389	DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
				390	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 1 (attached)
				391	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ)
				392	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				393	- msub gone
				394	llist_count(&msub_list) == 0
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	395	cm_service_result_sent == 2
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	396	DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5)
Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	397	===== test_ms_timeout_cm_auth_resp: SUCCESS
Neels Hofmeyr	6a29d32	2017-01-25 15:04:16 +0100	[diff] [blame]	398
Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	399	===== test_ms_timeout_paging
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	400	- Total time passed: 0.000000 s
				401	- Location Update request causes a GSUP LU request to HLR
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	402	MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	403	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	404	DMSC msub_fsm{active}: Allocated
				405	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				406	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				407	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				408	DMSC dummy_msc_i{0}: Allocated
				409	DMSC dummy_msc_i{0}: is child of msub_fsm
				410	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				411	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				412	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
				413	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
				414	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
				415	DREF 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)
				416	DREF 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)
				417	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
				418	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
				419	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN (no Auth)
				420	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	421	DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	422	DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
				423	DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	424	DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
				425	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
				426	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
				427	DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol	1086e20	2021-07-02 18:36:32 +0200	[diff] [blame]	428	DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smith	cbf2c93	2019-05-06 13:09:55 +0200	[diff] [blame]	429	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	430	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
				431	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_auth()
				432	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_post_ciph()
Harald Welte	544a32f	2020-06-21 22:15:53 +0200	[diff] [blame]	433	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN encode: COMMON_ID on GERAN-A
				434	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	435	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node_4()
				436	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
				437	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Allocated
				438	DVLR 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)
				439	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
				440	GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f02801020a0101
				441	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
				442	DREF 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)
				443	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	444	lu_result_sent == 0
				445	- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	446	<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101
				447	DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	448	DVLR IMSI:901700000004620 has MSISDN:46071
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	449	DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071)
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	450	GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101
				451	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	452	<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
				453	lu_result_sent == 0
				454	- HLR also sends GSUP _UPDATE_LOCATION_RESULT
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	455	<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f00a0101
				456	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
				457	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
				458	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
				459	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
				460	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				461	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				462	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
				463	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
				464	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Allocated
				465	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				466	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
				467	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
				468	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
				469	- sending LU Accept for IMSI-901700000004620:MSISDN-46071:GERAN-A:LU
				470	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + attached: now used by 3 (active-conn,vlr_gsup_rx,attached)
				471	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
				472	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
				473	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU))
				474	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				475	DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Deferring: will deallocate with upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU)
				476	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
				477	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED
				478	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_AUTHENTICATED
				479	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: - lu: now used by 0 (-)
				480	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: Received Event MSC_A_EV_UNUSED
				481	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_AUTHENTICATED}: state_chg to MSC_A_ST_RELEASING
				482	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
				483	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
				484	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 5 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter,vlr_subscr_cancel_attach_fsm)
				485	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 4 (active-conn,vlr_gsup_rx,attached,msc_a_fsm_releasing_onenter)
				486	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
				487	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				488	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				489	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 3 (active-conn,vlr_gsup_rx,attached)
				490	DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated, including all deferred deallocations
				491	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (active-conn,attached)
Neels Hofmeyr	4068ab2	2018-04-01 20:55:54 +0200	[diff] [blame]	492	<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
				493	- LU was successful, and the conn has already been closed
				494	lu_result_sent == 1
				495	bssap_clear_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	496	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				497	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				498	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				499	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				500	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				501	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				502	DVLR 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))
				503	DVLR 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)
				504	DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
				505	DVLR 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)
				506	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				507	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
				508	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				509	DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
				510	DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
				511	DMSC msub_fsm{active}: state_chg to terminating
				512	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU))
				513	DMSC 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))
				514	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Removing from parent msub_fsm
				515	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				516	DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
				517	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 1 (attached)
				518	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU)
				519	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				520	- msub gone
				521	llist_count(&msub_list) == 0
				522
				523
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	524	- an SMS is sent, MS is paged
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	525	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + test_ms_timeout_paging: now used by 2 (attached,test_ms_timeout_paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	526	llist_count(&vsub->cs.requests) == 0
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	527	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS-receiver: now used by 3 (attached,test_ms_timeout_paging,SMS-receiver)
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	528	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS: now used by 4 (attached,test_ms_timeout_paging,SMS-receiver,SMS)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	529	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) New transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	530	DLSMS SMC(0) instance created for network
				531	DLSMS SMR(0) instance created for network.
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	532	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) Going to send a MT SMS
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	533	DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
				534	DLSMS SMR(0) TX SMS RP-DATA
				535	DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
				536	DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
				537	DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	538	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) Initiating Paging due to MMSMS_EST_REQ
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	539	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Starting paging
				540	paging request (SIGNALLING_LOW_PRIO) to IMSI-901700000004620:MSISDN-46071 on GERAN-A
				541	strcmp(paging_expecting_imsi, vsub->imsi) == 0
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	542	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + Paging: now used by 5 (attached,test_ms_timeout_paging,SMS-receiver,SMS,Paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	543	llist_count(&vsub->cs.requests) == 1
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	544	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - test_ms_timeout_paging: now used by 4 (attached,SMS-receiver,SMS,Paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	545	paging_sent == 1
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	546	- time passes and no paging result is received
				547	- Total time passed: 9.000000 s
				548	- the paging timeout has not yet expired
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	549	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + test_ms_timeout_paging: now used by 5 (attached,SMS-receiver,SMS,Paging,test_ms_timeout_paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	550	vsub->cs.is_paging == 1
				551	- another request is added to the list but does not cause another paging
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	552	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS-receiver: now used by 6 (attached,2*SMS-receiver,SMS,Paging,test_ms_timeout_paging)
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	553	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS: now used by 7 (attached,2SMS-receiver,2SMS,Paging,test_ms_timeout_paging)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	554	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) New transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	555	DLSMS SMC(0) instance created for network
				556	DLSMS SMR(0) instance created for network.
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	557	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) Going to send a MT SMS
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	558	DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
				559	DLSMS SMR(0) TX SMS RP-DATA
				560	DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
				561	DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
				562	DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	563	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) Initiating Paging due to MMSMS_EST_REQ
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	564	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Already paging, not starting another request
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	565	llist_count(&vsub->cs.requests) == 2
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	566	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - test_ms_timeout_paging: now used by 6 (attached,2SMS-receiver,2SMS,Paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	567	paging_sent == 0
				568	- the paging timeout expires, the paging as well as the requests are canceled
				569	- Total time passed: 11.000000 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	570	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Paging Response action (expired)
				571	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Removing Paging Request
				572	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) mmsms_paging_cb(expired)
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	573	DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
				574	DLSMS SMC(0) MM layer is released
				575	DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	576	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) MNSMS-ERROR-IND, no cause
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	577	DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
				578	DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
				579	DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
				580	DLSMS SMR(0) TX: MNSMS-REL-REQ
				581	DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	582	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS-receiver: now used by 5 (attached,SMS-receiver,2*SMS,Paging)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	583	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000001 tid-0) Freeing transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	584	DLSMS SMR(0) clearing SMR instance
				585	DLSMS SMC(0) clearing instance
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	586	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS: now used by 4 (attached,SMS-receiver,SMS,Paging)
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	587	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Paging Response action (expired)
				588	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Removing Paging Request
				589	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) mmsms_paging_cb(expired)
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	590	DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
				591	DLSMS SMC(0) MM layer is released
				592	DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	593	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) MNSMS-ERROR-IND, no cause
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	594	DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
				595	DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
				596	DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
				597	DLSMS SMR(0) TX: MNSMS-REL-REQ
				598	DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	599	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS-receiver: now used by 3 (attached,SMS,Paging)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	600	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000002 tid-1) Freeing transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	601	DLSMS SMR(0) clearing SMR instance
				602	DLSMS SMC(0) clearing instance
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	603	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS: now used by 2 (attached,Paging)
				604	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - Paging: now used by 1 (attached)
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	605	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + test_ms_timeout_paging: now used by 2 (attached,test_ms_timeout_paging)
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	606	vsub->cs.is_paging == 0
				607	llist_count(&vsub->cs.requests) == 0
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	608
				609
Neels Hofmeyr	facd57a	2017-12-15 03:48:48 +0100	[diff] [blame]	610	- Now that the timeout has expired, another Paging is sent on request
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	611	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS-receiver: now used by 3 (attached,test_ms_timeout_paging,SMS-receiver)
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	612	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + SMS: now used by 4 (attached,test_ms_timeout_paging,SMS-receiver,SMS)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	613	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) New transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	614	DLSMS SMC(0) instance created for network
				615	DLSMS SMR(0) instance created for network.
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	616	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) Going to send a MT SMS
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	617	DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
				618	DLSMS SMR(0) TX SMS RP-DATA
				619	DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
				620	DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
				621	DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	622	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) Initiating Paging due to MMSMS_EST_REQ
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	623	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Starting paging
				624	paging request (SIGNALLING_LOW_PRIO) to IMSI-901700000004620:MSISDN-46071 on GERAN-A
				625	strcmp(paging_expecting_imsi, vsub->imsi) == 0
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	626	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + Paging: now used by 5 (attached,test_ms_timeout_paging,SMS-receiver,SMS,Paging)
Neels Hofmeyr	facd57a	2017-12-15 03:48:48 +0100	[diff] [blame]	627	llist_count(&vsub->cs.requests) == 1
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	628	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - test_ms_timeout_paging: now used by 4 (attached,SMS-receiver,SMS,Paging)
Neels Hofmeyr	facd57a	2017-12-15 03:48:48 +0100	[diff] [blame]	629	paging_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	630
				631
Neels Hofmeyr	facd57a	2017-12-15 03:48:48 +0100	[diff] [blame]	632	- subscriber detaches, pagings are canceled
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	633	MSC <--GERAN-A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	634	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	635	DMSC msub_fsm{active}: Allocated
				636	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				637	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				638	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				639	DMSC dummy_msc_i{0}: Allocated
				640	DMSC dummy_msc_i{0}: is child of msub_fsm
				641	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				642	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				643	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_IMSI_DETACH_IND
Neels Hofmeyr	46d526a	2020-05-29 03:27:50 +0200	[diff] [blame]	644	DMM IMSI DETACH INDICATION: IMSI-901700000004620
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	645	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + gsm48_rx_mm_imsi_detach_ind: now used by 5 (attached,SMS-receiver,SMS,Paging,gsm48_rx_mm_imsi_detach_ind)
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	646	DMM IMSI DETACH for IMSI-901700000004620:MSISDN-46071
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	647	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + active-conn: now used by 6 (attached,SMS-receiver,SMS,Paging,gsm48_rx_mm_imsi_detach_ind,active-conn)
				648	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Paging Response action (expired)
				649	DPAG Paging: IMSI-901700000004620:MSISDN-46071 for MT-SMS: Removing Paging Request
				650	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) mmsms_paging_cb(expired)
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	651	DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
				652	DLSMS SMC(0) MM layer is released
				653	DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	654	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) MNSMS-ERROR-IND, no cause
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	655	DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
				656	DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
				657	DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
				658	DLSMS SMR(0) TX: MNSMS-REL-REQ
				659	DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	660	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS-receiver: now used by 5 (attached,SMS,Paging,gsm48_rx_mm_imsi_detach_ind,active-conn)
Neels Hofmeyr	ff7074a	2019-02-28 05:50:06 +0100	[diff] [blame]	661	DLSMS trans(SMS IMSI-901700000004620:MSISDN-46071 callref-0x40000003 tid-0) Freeing transaction
Max	4813152	2019-01-16 12:47:39 +0100	[diff] [blame]	662	DLSMS SMR(0) clearing SMR instance
				663	DLSMS SMC(0) clearing instance
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	664	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - SMS: now used by 4 (attached,Paging,gsm48_rx_mm_imsi_detach_ind,active-conn)
				665	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - Paging: now used by 3 (attached,gsm48_rx_mm_imsi_detach_ind,active-conn)
				666	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_subscr_cancel_attach_fsm: now used by 4 (attached,gsm48_rx_mm_imsi_detach_ind,active-conn,vlr_subscr_cancel_attach_fsm)
				667	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 3 (attached,gsm48_rx_mm_imsi_detach_ind,active-conn)
Pau Espin Pedrol	1086e20	2021-07-02 18:36:32 +0200	[diff] [blame]	668	DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	669	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - attached: now used by 2 (gsm48_rx_mm_imsi_detach_ind,active-conn)
				670	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - gsm48_rx_mm_imsi_detach_ind: now used by 1 (active-conn)
				671	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_CN_CLOSE
				672	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_RELEASING
				673	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: Releasing: msc_a use is 1 (rx_from_ms)
				674	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + msc_a_fsm_releasing_onenter: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				675	DREF 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)
				676	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				677	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 2 (rx_from_ms,wait-Clear-Complete)
				678	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				679	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				680	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - msc_a_fsm_releasing_onenter: now used by 1 (active-conn)
				681	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: - rx_from_ms: now used by 1 (wait-Clear-Complete)
Neels Hofmeyr	4068ab2	2018-04-01 20:55:54 +0200	[diff] [blame]	682	bssap_clear_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	683	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				684	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				685	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				686	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				687	DBSSAP msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				688	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				689	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				690	DREF msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: max total use count was 2
				691	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				692	DMSC msub(IMSI-901700000004620:MSISDN-46071) MSC-A terminated
				693	DMSC msub(IMSI-901700000004620:MSISDN-46071) 1 MSC-I still active
				694	DMSC msub_fsm{active}: state_chg to terminating
				695	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE))
				696	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Terminating in cascade, depth 3 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE))
				697	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Removing from parent msub_fsm
				698	DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE)
				699	DMSC msub(IMSI-901700000004620:MSISDN-46071) Free
				700	DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-)
				701	DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 7)
				702	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE)
				703	DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				704	- msub gone
				705	llist_count(&msub_list) == 0
Neels Hofmeyr	dfdc61d	2018-03-02 00:40:58 +0100	[diff] [blame]	706	===== test_ms_timeout_paging: SUCCESS
Neels Hofmeyr	2ff5bcd	2017-12-15 03:02:27 +0100	[diff] [blame]	707
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	708	===== test_classmark_update_timeout
				709	- Total time passed: 0.000000 s
				710	- Location Update request causes a GSUP Send Auth Info request to HLR
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	711	MSC <--GERAN-A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	712	new conn
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	713	DMSC msub_fsm{active}: Allocated
				714	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: Allocated
				715	DMSC msc_a{MSC_A_ST_VALIDATE_L3}: is child of msub_fsm
				716	DMSC msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_VALIDATE_L3
				717	DMSC dummy_msc_i{0}: Allocated
				718	DMSC dummy_msc_i{0}: is child of msub_fsm
				719	DREF msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: + rx_from_ms: now used by 1 (rx_from_ms)
				720	DBSSAP msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: RAN decode: COMPL_L3
				721	DRLL msc_a(unknown:GERAN-A:NONE){MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_LOC_UPD_REQUEST
				722	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: LOCATION UPDATING REQUEST: MI=IMSI-901700000004620 LU-type=IMSI-ATTACH
				723	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: USIM: old LAI: 001-868-1
				724	DREF 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)
				725	DREF 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)
				726	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Allocated
				727	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000004620:GERAN-A:LU)
				728	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth+Ciph
				729	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Neels Hofmeyr	7c5346c	2019-02-19 02:36:35 +0100	[diff] [blame]	730	DREF VLR subscr unknown + _lu_fsm_associate_vsub: now used by 1 (_lu_fsm_associate_vsub)
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	731	DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
				732	DVLR New subscr, IMSI: 901700000004620
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	733	DREF VLR subscr IMSI-901700000004620 + active-conn: now used by 2 (_lu_fsm_associate_vsub,active-conn)
				734	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: Received Event MSC_A_EV_COMPLETE_LAYER_3_OK
				735	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_VALIDATE_L3}: state_chg to MSC_A_ST_AUTH_CIPH
				736	DREF VLR subscr IMSI-901700000004620 - _lu_fsm_associate_vsub: now used by 1 (active-conn)
Pau Espin Pedrol	1086e20	2021-07-02 18:36:32 +0200	[diff] [blame]	737	DVLR set Last E-UTRAN PLMN ID on subscriber: (none)
Oliver Smith	cbf2c93	2019-05-06 13:09:55 +0200	[diff] [blame]	738	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1_pre()
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	739	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
				740	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
				741	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Allocated
				742	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
				743	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
Neels Hofmeyr	63b2464	2019-12-12 01:31:04 +0100	[diff] [blame]	744	GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f02801020a0101
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	745	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
				746	DREF 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)
				747	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	748	lu_result_sent == 0
				749	- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	750	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000a0101
				751	DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx)
				752	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	753	DVLR SUBSCR(IMSI-901700000004620) Received 1 auth tuples
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	754	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP
				755	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
				756	- sending GSM Auth Request for IMSI-901700000004620:GERAN-A:LU: tuple use_count=1 key_seq=0 auth_types=0x1 and...
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	757	- ...rand=585df1ae287f6e273dce07090d61320b
				758	- ...expecting sres=2d8b2c3e
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	759	DREF VLR subscr IMSI-901700000004620 - vlr_gsup_rx: now used by 1 (active-conn)
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	760	<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0
				761	lu_result_sent == 0
				762	auth_request_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	763
				764
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	765	- MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS -- but needs Classmark 2 to determine whether A5/3 is supported
Neels Hofmeyr	7814a83	2018-12-26 00:40:18 +0100	[diff] [blame]	766	MSC <--GERAN-A-- MS: GSM48_MT_MM_AUTH_RESP
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	767	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: + rx_from_ms: now used by 2 (lu,rx_from_ms)
				768	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN decode: DTAP
				769	DRLL msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: Dispatching 04.08 message: MM GSM48_MT_MM_AUTH_RESP
				770	DMM msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: MM GSM AUTHENTICATION RESPONSE (sres = 2d8b2c3e)
				771	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
Neels Hofmeyr	361e571	2019-01-03 02:32:14 +0100	[diff] [blame]	772	DVLR SUBSCR(IMSI-901700000004620) AUTH on GERAN received SRES/RES: 2d8b2c3e (4 bytes)
				773	DVLR SUBSCR(IMSI-901700000004620) AUTH established GSM security context
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	774	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
				775	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
				776	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				777	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU)
Neels Hofmeyr	3189f39	2022-10-26 18:11:58 +0200	[diff] [blame]	778	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_SUCCESS
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	779	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
				780	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode
				781	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: For A5/3, we still need Classmark 2
				782	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: RAN encode: CLASSMARK_REQUEST on GERAN-A
				783	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				784	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: state_chg to MSC_A_ST_WAIT_CLASSMARK_UPDATE
				785	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH
				786	DVLR VLR_Authenticate(IMSI-901700000004620:GERAN-A:LU){VLR_SUB_AS_AUTHENTICATED}: Deallocated
				787	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: - rx_from_ms: now used by 1 (lu)
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	788	lu_result_sent == 0
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	789
				790
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	791	- But the BSSMAP Classmark Update never arrives
				792	- At first, we're still waiting
				793	- Total time passed: 0.000423 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	794	llist_count(&msub_list) == 1
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	795	lu_result_sent == 0
				796	- Total time passed: 1.000658 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	797	llist_count(&msub_list) == 1
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	798	lu_result_sent == 0
				799	- Total time passed: 2.000893 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	800	llist_count(&msub_list) == 1
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	801	lu_result_sent == 0
				802	- Total time passed: 3.001128 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	803	llist_count(&msub_list) == 1
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	804	lu_result_sent == 0
				805	- Total time passed: 4.001363 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	806	llist_count(&msub_list) == 1
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	807	lu_result_sent == 0
				808	- Total time passed: 5.001598 s
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	809	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: Timeout of X1
				810	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: Received Event MSC_A_EV_CN_CLOSE
				811	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: - lu: now used by 0 (-)
				812	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: Received Event MSC_A_EV_UNUSED
				813	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: Event MSC_A_EV_UNUSED not permitted
				814	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_WAIT_CLASSMARK_UPDATE}: state_chg to MSC_A_ST_RELEASING
				815	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Releasing: msc_a use is 0 (-)
				816	DREF VLR subscr IMSI-901700000004620 + msc_a_fsm_releasing_onenter: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				817	DREF 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)
				818	- sending LU Reject for IMSI-901700000004620:GERAN-A:LU, cause 22
				819	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_DONE
				820	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_CN_CLOSE
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	821	DREF VLR subscr IMSI-901700000004620 - vlr_subscr_cancel_attach_fsm: now used by 2 (active-conn,msc_a_fsm_releasing_onenter)
				822	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: + wait-Clear-Complete: now used by 1 (wait-Clear-Complete)
				823	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN encode: CLEAR_COMMAND on GERAN-A
				824	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Received Event MSC_I_EV_FROM_A_FORWARD_ACCESS_SIGNALLING_REQUEST
				825	DREF VLR subscr IMSI-901700000004620 - msc_a_fsm_releasing_onenter: now used by 1 (active-conn)
Neels Hofmeyr	c036b79	2018-11-29 22:37:51 +0100	[diff] [blame]	826	- RAN_CONN_TIMEOUT has passed, conn is gone.
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	827	bssap_clear_sent == 1
Neels Hofmeyr	c4628a3	2018-12-07 14:47:34 +0100	[diff] [blame]	828	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: RAN decode: CLEAR_COMPLETE
				829	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: - wait-Clear-Complete: now used by 0 (-)
				830	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: Received Event MSC_A_EV_UNUSED
				831	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASING}: state_chg to MSC_A_ST_RELEASED
				832	DBSSAP msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Released: msc_a use is 0 (-)
				833	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
				834	DVLR 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))
				835	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000004620:GERAN-A:LU)
				836	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
				837	DVLR vlr_lu_fsm(IMSI-901700000004620:GERAN-A:LU){VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				838	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Removing from parent msub_fsm
				839	DREF msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: max total use count was 3
				840	DMSC msub_fsm{active}: Received Event MSUB_EV_ROLE_TERMINATED
				841	DMSC msub(IMSI-901700000004620) MSC-A terminated
				842	DMSC msub(IMSI-901700000004620) 1 MSC-I still active
				843	DMSC msub_fsm{active}: state_chg to terminating
				844	DMSC msub_fsm{terminating}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_REGULAR, caused by: msc_a(IMSI-901700000004620:GERAN-A:LU))
				845	DMSC 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))
				846	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Removing from parent msub_fsm
				847	DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				848	DMSC msub(IMSI-901700000004620) Free
				849	DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-)
				850	DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3)
				851	DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU)
				852	DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations
				853	- msub gone
				854	llist_count(&msub_list) == 0
Neels Hofmeyr	3117b70	2018-09-13 03:23:07 +0200	[diff] [blame]	855	lu_result_sent == 2
				856	===== test_classmark_update_timeout: SUCCESS
				857