Actions
Bug #2921
closedSecond of two subsequent runs of TC_lu_by_tmsi_noauth_unknown failed
Start date:
02/10/2018
Due date:
% Done:
0%
Resolution:
Spec Reference:
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!!!
Updated by laforge over 5 years ago
- Assignee changed from 4368 to neels
- Priority changed from Normal to Low
this is probably long resolved...
Updated by neels almost 5 years ago
- Status changed from New to Rejected
killing this issue since it is about outdated code.
Actions