Project

General

Profile

Bug #2921

Second of two subsequent runs of TC_lu_by_tmsi_noauth_unknown failed

Added by laforge 3 months ago.

Status:
New
Priority:
Normal
Assignee:
sysmocom
Category:
-
Target version:
-
Start date:
02/10/2018
Due date:
% Done:

0%

Resolution:

Description

Successful First run

Sat Feb 10 10:01:31 2018 DLCTRL <0018> control_if.c:497 accept()ed new CTRL connection from (r=127.0.0.1:9999<->l=127.0.0.1:4255)
Sat Feb 10 10:01:31 2018 DMNCC <0004> mncc_sock.c:274 MNCC Socket has connection with external call control application
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface.c:138 The calling BSC (RI=SSN_PC,PC=0.24.1,SSN=BSSAP) is unknown to this MSC ...
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface.c:458 Adding new BSC connection for BSC RI=SSN_PC,PC=0.24.1,SSN=BSSAP...
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface.c:578 N-UNITDATA.ind(00 04 30 04 01 00 )
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface_bssap.c:188 Rx BSSMAP UDT: 00 04 30 04 01 00 
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface_bssap.c:162 Rx BSSMAP UDT RESET
Sat Feb 10 10:01:31 2018 DBSSAP <0010> a_iface_bssap.c:115 Rx BSSMAP RESET from BSC RI=SSN_PC,PC=0.24.1,SSN=BSSAP, sending RESET ACK
Sat Feb 10 10:01:32 2018 DLGSUP <001b> gsup_client.c:76 GSUP connecting to 127.0.0.1:4222
Sat Feb 10 10:01:32 2018 DLINP <0013> input/ipa.c:129 connection done.
Sat Feb 10 10:01:32 2018 DLINP <0013> input/ipaccess.c:707 received ID get
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:533 N-CONNECT.ind(0, 00 1c 57 05 08 00 62 22 40 00 17 00 2a 17 0f 05 08 02 62 f2 20 99 99 52 05 f4 01 02 03 04 )
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:277 Rx BSSMAP COMPLETE L3 INFO (conn_id=0)
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:73 (subscr unknown, conn_id 0) A-Interface subscriber connection successfully allocated!
Sat Feb 10 10:01:32 2018 DMM <0002> fsm.c:243 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_INIT}: Allocated
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:332 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:66 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Sat Feb 10 10:01:32 2018 DMM <0002> gsm_04_08.c:345 LOCATION UPDATING REQUEST: MI(TMSI)=16909060 type=IMSI ATTACH
Sat Feb 10 10:01:32 2018 DMM <0002> gsm_04_08.c:390 LU/new-LAC: 39321/23
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:243 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: Allocated
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:273 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: is child of Subscr_Conn(16909060)[0x6120000084a0]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1437 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: rev=R99 net=GERAN (no Auth)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1443 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:365 New subscr, TMSI: 0x01020304
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:878 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:884 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:155 (subscr TMSI:0x01020304, conn_id 0) Passing DTAP message from MSC to BSC
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:169 (subscr TMSI:0x01020304, conn_id 0) N-DATA.req([])
Sat Feb 10 10:01:32 2018 DMM <0002> osmo_msc.c:61 TMSI:0x01020304: bump: conn still being established (SUBSCR_CONN_S_NEW)
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(0, 00 06 54 12 03 52 49 02 )
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:93 (subscr TMSI:0x01020304, conn_id 0) Found A subscriber for conn_id 0
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:558 (subscr TMSI:0x01020304, conn_id 0) Rx BSSMAP DT1 CLASSMARK UPDATE
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:343 (subscr TMSI:0x01020304, conn_id 0) Rx BSSMAP CLASSMARK UPDATE
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(0, 01 00 0b 05 59 08 29 26 24 00 00 00 00 31 )
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:93 (subscr TMSI:0x01020304, conn_id 0) Found A subscriber for conn_id 0
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:594 (subscr TMSI:0x01020304, conn_id 0) Rx DTAP 01 00 0b 05 59 08 29 26 24 00 00 00 00 31 
Sat Feb 10 10:01:32 2018 DMM <0002> gsm_04_08.c:296 IDENTITY RESPONSE: MI(IMSI)=262420000000013
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:378 set IMSI on subscriber; IMSI=262420000000013 id=262420000000013
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:935 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:378 set IMSI on subscriber; IMSI=262420000000013 id=262420000000013
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:855 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:822 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:790 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:751 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:760 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:243 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_INIT}: Allocated
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:273 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(16909060)[0x612000008620]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:167 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:147 GSUP tx: 04010862420200000010f3
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:84 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Sat Feb 10 10:01:32 2018 DMM <0002> osmo_msc.c:61 IMSI:262420000000013: bump: conn still being established (SUBSCR_CONN_S_NEW)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:809 GSUP rx 20: 10010862420200000010f3080706942103000031
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:665 IMSI:262420000000013 has MSISDN:491230000013
Sat Feb 10 10:01:32 2018 DVLR <000e> gsm_04_08.c:3709 SUBSCR(MSISDN:491230000013) VLR: update for IMSI=262420000000013 (MSISDN=491230000013, used=2)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:147 GSUP tx: 12010862420200000010f3
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:809 GSUP rx 11: 06010862420200000010f3
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:755 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1170 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:106 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:107 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:107 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(16909060)[0x612000008620]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:107 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_DONE}: Freeing instance
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:318 upd_hlr_vlr_fsm(16909060)[0x6120000087a0]{UPD_HLR_VLR_S_DONE}: Deallocated
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:107 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1178 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:243 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_INIT}: Allocated
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:273 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(16909060)[0x612000008620]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:396 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:243 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_INIT}: Allocated
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:273 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(16909060)[0x612000008920]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:280 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:203 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:204 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:204 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(16909060)[0x612000008920]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:204 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_DONE}: Freeing instance
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:318 sub_pres_vlr_fsm(16909060)[0x612000008aa0]{SUB_PRES_VLR_S_DONE}: Deallocated
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:204 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:407 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:416 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF
Sat Feb 10 10:01:32 2018 DMM <0002> gsm_04_08.c:255 -> MSISDN:491230000013 LOCATION UPDATE ACCEPT (TMSI = 0x5b96e2d5)
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:155 (subscr MSISDN:491230000013, conn_id 0) Passing DTAP message from MSC to BSC
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:169 (subscr MSISDN:491230000013, conn_id 0) N-DATA.req([])
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(0, 01 00 02 05 9b )
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:93 (subscr MSISDN:491230000013, conn_id 0) Found A subscriber for conn_id 0
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface_bssap.c:594 (subscr MSISDN:491230000013, conn_id 0) Rx DTAP 01 00 02 05 9b 
Sat Feb 10 10:01:32 2018 DMM <0002> gsm_04_08.c:1075 TMSI Reallocation Completed. Subscriber: MSISDN:491230000013
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr.c:948 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1213 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:332 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:366 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:741 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:741 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(16909060)[0x612000008620]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:741 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_DONE}: Freeing instance
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:318 lu_compl_vlr_fsm(16909060)[0x612000008920]{LU_COMPL_VLR_S_DONE}: Deallocated
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:708 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
Sat Feb 10 10:01:32 2018 DMM <0002> vlr_lu_fsm.c:700 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:77 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:84 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:132 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:168 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:169 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:243 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Sat Feb 10 10:01:32 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
Sat Feb 10 10:01:32 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(16909060)[0x6120000084a0]
Sat Feb 10 10:01:32 2018 DVLR <000e> vlr_lu_fsm.c:1370 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
Sat Feb 10 10:01:32 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_DONE}: Freeing instance
Sat Feb 10 10:01:32 2018 DVLR <000e> fsm.c:318 vlr_lu_fsm(16909060)[0x612000008620]{VLR_ULA_S_DONE}: Deallocated
Sat Feb 10 10:01:32 2018 DMM <0002> osmo_msc.c:328 msc_subscr_conn_close(vsub=MSISDN:491230000013, cause=2): no conn fsm, releasing directly without release event.
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:420 (subscr MSISDN:491230000013, conn_id 0) Tx BSSMAP CLEAR COMMAND to BSC
Sat Feb 10 10:01:32 2018 DMM <0002> subscr_conn.c:243 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_RELEASED}: Freeing instance
Sat Feb 10 10:01:32 2018 DMM <0002> fsm.c:318 Subscr_Conn(16909060)[0x6120000084a0]{SUBSCR_CONN_S_RELEASED}: Deallocated
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(0, 00 01 21 )
Sat Feb 10 10:01:32 2018 DBSSAP <0010> a_iface.c:90 (conn_id 0) Removing A-interface conn
Sat Feb 10 10:01:32 2018 DLCTRL <0018> control_if.c:173 close()d CTRL connection (r=127.0.0.1:9999<->l=127.0.0.1:4255)
Sat Feb 10 10:01:32 2018 DMNCC <0004> mncc_sock.c:85 MNCC Socket has LOST connection
Sat Feb 10 10:01:32 2018 DCC <0001> gsm_04_08.c:191 Clearing all currently active transactions!!!
Sat Feb 10 10:01:32 2018 DLINP <0013> input/ipa.c:67 connection closed with server
Sat Feb 10 10:01:33 2018 DLGSUP <001b> gsup_client.c:76 GSUP connecting to 127.0.0.1:4222

Unsuccessful second run

Sat Feb 10 10:01:35 2018 DLGSUP <001b> gsup_client.c:76 GSUP connecting to 127.0.0.1:4222
Sat Feb 10 10:01:36 2018 DLCTRL <0018> control_if.c:497 accept()ed new CTRL connection from (r=127.0.0.1:9999<->l=127.0.0.1:4255)
Sat Feb 10 10:01:36 2018 DMNCC <0004> mncc_sock.c:274 MNCC Socket has connection with external call control application
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface.c:578 N-UNITDATA.ind(00 04 30 04 01 00 )
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:188 Rx BSSMAP UDT: 00 04 30 04 01 00 
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:162 Rx BSSMAP UDT RESET
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:115 Rx BSSMAP RESET from BSC RI=SSN_PC,PC=0.24.1,SSN=BSSAP, sending RESET ACK
Sat Feb 10 10:01:36 2018 DLGSUP <001b> gsup_client.c:76 GSUP connecting to 127.0.0.1:4222
Sat Feb 10 10:01:36 2018 DLINP <0013> input/ipa.c:129 connection done.
Sat Feb 10 10:01:36 2018 DLINP <0013> input/ipaccess.c:707 received ID get
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface.c:533 N-CONNECT.ind(1, 00 1c 57 05 08 00 62 22 40 00 17 00 2a 17 0f 05 08 02 62 f2 20 99 99 52 05 f4 01 02 03 04 )
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:277 Rx BSSMAP COMPLETE L3 INFO (conn_id=1)
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:73 (subscr unknown, conn_id 1) A-Interface subscriber connection successfully allocated!
Sat Feb 10 10:01:36 2018 DMM <0002> fsm.c:243 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_INIT}: Allocated
Sat Feb 10 10:01:36 2018 DMM <0002> subscr_conn.c:332 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START
Sat Feb 10 10:01:36 2018 DMM <0002> subscr_conn.c:66 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW
Sat Feb 10 10:01:36 2018 DMM <0002> gsm_04_08.c:345 LOCATION UPDATING REQUEST: MI(TMSI)=16909060 type=IMSI ATTACH
Sat Feb 10 10:01:36 2018 DMM <0002> gsm_04_08.c:390 LU/new-LAC: 39321/23
Sat Feb 10 10:01:36 2018 DVLR <000e> fsm.c:243 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: Allocated
Sat Feb 10 10:01:36 2018 DVLR <000e> fsm.c:273 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: is child of Subscr_Conn(16909060)[0x61200000b1a0]
Sat Feb 10 10:01:36 2018 DVLR <000e> vlr_lu_fsm.c:1437 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: rev=R99 net=GERAN (no Auth)
Sat Feb 10 10:01:36 2018 DVLR <000e> vlr_lu_fsm.c:1443 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
Sat Feb 10 10:01:36 2018 DVLR <000e> vlr.c:365 New subscr, TMSI: 0x01020304
Sat Feb 10 10:01:36 2018 DVLR <000e> vlr_lu_fsm.c:878 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi()
Sat Feb 10 10:01:36 2018 DVLR <000e> vlr_lu_fsm.c:884 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface.c:155 (subscr TMSI:0x01020304, conn_id 1) Passing DTAP message from MSC to BSC
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface.c:169 (subscr TMSI:0x01020304, conn_id 1) N-DATA.req([])
Sat Feb 10 10:01:36 2018 DMM <0002> osmo_msc.c:61 TMSI:0x01020304: bump: conn still being established (SUBSCR_CONN_S_NEW)
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(1, 00 06 54 12 03 52 49 02 )
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:93 (subscr TMSI:0x01020304, conn_id 1) Found A subscriber for conn_id 1
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:558 (subscr TMSI:0x01020304, conn_id 1) Rx BSSMAP DT1 CLASSMARK UPDATE
Sat Feb 10 10:01:36 2018 DBSSAP <0010> a_iface_bssap.c:343 (subscr TMSI:0x01020304, conn_id 1) Rx BSSMAP CLASSMARK UPDATE
Sat Feb 10 10:01:37 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(1, 01 00 0b 05 59 08 29 26 24 00 00 00 00 31 )
Sat Feb 10 10:01:37 2018 DBSSAP <0010> a_iface_bssap.c:93 (subscr TMSI:0x01020304, conn_id 1) Found A subscriber for conn_id 1
Sat Feb 10 10:01:37 2018 DBSSAP <0010> a_iface_bssap.c:594 (subscr TMSI:0x01020304, conn_id 1) Rx DTAP 01 00 0b 05 59 08 29 26 24 00 00 00 00 31 
Sat Feb 10 10:01:37 2018 DMM <0002> gsm_04_08.c:296 IDENTITY RESPONSE: MI(IMSI)=262420000000013
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:378 set IMSI on subscriber; IMSI=262420000000013 id=262420000000013
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:935 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: Received Event VLR_ULA_E_ID_IMSI
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:378 set IMSI on subscriber; IMSI=262420000000013 id=262420000000013
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:855 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node1()
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:822 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_auth()
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:790 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_post_ciph()
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:751 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: vlr_loc_upd_node_4()
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:760 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_IMSI}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
Sat Feb 10 10:01:37 2018 DVLR <000e> fsm.c:243 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_INIT}: Allocated
Sat Feb 10 10:01:37 2018 DVLR <000e> fsm.c:273 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(16909060)[0x61200000b320]
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:167 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:147 GSUP tx: 04010862420200000010f3
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr_lu_fsm.c:84 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
Sat Feb 10 10:01:37 2018 DMM <0002> osmo_msc.c:61 IMSI:262420000000013: bump: conn still being established (SUBSCR_CONN_S_NEW)
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:809 GSUP rx 20: 10010862420200000010f3080706942103000031
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:665 IMSI:262420000000013 has MSISDN:491230000013
Sat Feb 10 10:01:37 2018 DVLR <000e> gsm_04_08.c:3709 SUBSCR(MSISDN:491230000013) VLR: update for IMSI=262420000000013 (MSISDN=491230000013, used=2)
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:147 GSUP tx: 12010862420200000010f3
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:809 GSUP rx 11: 06010862420200000010f3
Sat Feb 10 10:01:37 2018 DVLR <000e> vlr.c:746 SUBSCR(MSISDN:491230000013) Rx GSUP LU Result without LU in progress
Sat Feb 10 10:01:41 2018 DMM <0002> fsm.c:182 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_NEW}: Timeout of T0
Sat Feb 10 10:01:41 2018 DVLR <000e> vlr_lu_fsm.c:1454 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_HLR_UPD}: Connection timed out
Sat Feb 10 10:01:41 2018 DMM <0002> gsm_04_08.c:213 Subscriber IMSI:262420000000013: LOCATION UPDATING REJECT
Sat Feb 10 10:01:41 2018 DBSSAP <0010> a_iface.c:155 (subscr IMSI:262420000000013, conn_id 1) Passing DTAP message from MSC to BSC
Sat Feb 10 10:01:41 2018 DBSSAP <0010> a_iface.c:169 (subscr IMSI:262420000000013, conn_id 1) N-DATA.req([])
Sat Feb 10 10:01:41 2018 DVLR <000e> vlr_lu_fsm.c:708 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_DONE
Sat Feb 10 10:01:41 2018 DMM <0002> vlr_lu_fsm.c:700 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
Sat Feb 10 10:01:41 2018 DMM <0002> subscr_conn.c:77 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU
Sat Feb 10 10:01:41 2018 DMM <0002> subscr_conn.c:91 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_NEW}: Close event, cause 1
Sat Feb 10 10:01:41 2018 DMM <0002> subscr_conn.c:123 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED
Sat Feb 10 10:01:41 2018 DMM <0002> subscr_conn.c:243 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Terminating (cause = OSMO_FSM_TERM_PARENT)
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Removing from parent vlr_lu_fsm(16909060)[0x61200000b320]
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Freeing instance
Sat Feb 10 10:01:41 2018 DVLR <000e> fsm.c:318 upd_hlr_vlr_fsm(16909060)[0x61200000b4a0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Deallocated
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(16909060)[0x61200000b1a0]
Sat Feb 10 10:01:41 2018 DVLR <000e> vlr_lu_fsm.c:1370 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
Sat Feb 10 10:01:41 2018 DVLR <000e> subscr_conn.c:243 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_DONE}: Freeing instance
Sat Feb 10 10:01:41 2018 DVLR <000e> fsm.c:318 vlr_lu_fsm(16909060)[0x61200000b320]{VLR_ULA_S_DONE}: Deallocated
Sat Feb 10 10:01:41 2018 DMM <0002> osmo_msc.c:328 msc_subscr_conn_close(vsub=IMSI:262420000000013, cause=2): no conn fsm, releasing directly without release event.
Sat Feb 10 10:01:41 2018 DBSSAP <0010> a_iface.c:420 (subscr IMSI:262420000000013, conn_id 1) Tx BSSMAP CLEAR COMMAND to BSC
Sat Feb 10 10:01:41 2018 DMM <0002> subscr_conn.c:243 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_RELEASED}: Freeing instance
Sat Feb 10 10:01:41 2018 DMM <0002> fsm.c:318 Subscr_Conn(16909060)[0x61200000b1a0]{SUBSCR_CONN_S_RELEASED}: Deallocated
Sat Feb 10 10:01:41 2018 DBSSAP <0010> a_iface.c:552 N-DATA.ind(1, 00 01 21 )
Sat Feb 10 10:01:41 2018 DBSSAP <0010> a_iface.c:90 (conn_id 1) Removing A-interface conn
Sat Feb 10 10:01:41 2018 DLINP <0013> input/ipa.c:67 connection closed with server
Sat Feb 10 10:01:41 2018 DLCTRL <0018> control_if.c:173 close()d CTRL connection (r=127.0.0.1:9999<->l=127.0.0.1:4255)
Sat Feb 10 10:01:41 2018 DMNCC <0004> mncc_sock.c:85 MNCC Socket has LOST connection
Sat Feb 10 10:01:41 2018 DCC <0001> gsm_04_08.c:191 Clearing all currently active transactions!!!

Also available in: Atom PDF