Hello,
We met a problem during the cellphone trying to attach to the network. The modules we ran are: Nano femtocell <- LAN -> osmo-hnbgw <--> osmo-msc <--> osmo-hlr. The cellphone with sysmcom USIM searched the network 90170 and then tried to register in it. The authentication was passed but the connection was released. The cellphone automatically repeated the attach again and again, but always failed.
In the output of HLR, it seems the authentication is OK: ---------------------- 20170606183004032 DAUC <0003> db_auc.c:222 901700000014922: Generated 5 vectors 20170606183004032 DAUC <0003> db_auc.c:227 901700000014922: Updating SQN=1728 in DB ... 20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED -> ISD SENT ----------------------
But in the output of MSC: ---------------------- 20170606183005665 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE IMSI:901700000014922 ... 20170606183005666 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE ACCEPT ... 20170606183005666 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333 via RAN_UTRAN_IU 20170606183005666 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0xcacde0 conn_id 0) 20170606183005666 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170606183005666 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e 00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22 00 3b 40 01 00 00 00 ) 20170606183005666 DVLR <001d> vlr_lu_fsm.c:321 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE 20170606183005666 DVLR <001d> vlr_lu_fsm.c:355 vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS 20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0xcd5250] 20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Freeing instance 20170606183005666 DVLR <001d> fsm.c:275 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Deallocated 20170606183005666 DVLR <001d> vlr_lu_fsm.c:700 vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE 20170606183005666 DMM <0002> vlr_lu_fsm.c:692 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED 20170606183005666 DMM <0002> subscr_conn.c:77 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU 20170606183005666 DMM <0002> subscr_conn.c:84 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED 20170606183005668 DMM <0002> subscr_conn.c:132 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 20170606183005668 DMM <0002> subscr_conn.c:168 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn 20170606183005668 DMM <0002> subscr_conn.c:169 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED 20170606183005668 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) ----------------------
Why is there a 'Received Event SUBSCR_CONN_E_BUMP'?
Regards Lin
Hi Lin,
On Tue, Jun 06, 2017 at 06:09:16PM +0800, Lin HUANG wrote:
In the output of HLR, it seems the authentication is OK:
20170606183004032 DAUC <0003> db_auc.c:222 901700000014922: Generated 5 vectors 20170606183004032 DAUC <0003> db_auc.c:227 901700000014922: Updating SQN=1728 in DB ... 20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED
-> ISD SENT
looks good
But in the output of MSC:
20170606183005665 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE IMSI:901700000014922 ... 20170606183005666 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE ACCEPT ... 20170606183005666 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333 via RAN_UTRAN_IU 20170606183005666 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0xcacde0 conn_id 0) 20170606183005666 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170606183005666 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e 00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22 00 3b 40 01 00 00 00 ) 20170606183005666 DVLR <001d> vlr_lu_fsm.c:321 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE 20170606183005666 DVLR <001d> vlr_lu_fsm.c:355 vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
^ Location updating is successful at this point. The Finite State Machine for LU is hence torn down:
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0xcd5250] 20170606183005666 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Freeing instance 20170606183005666 DVLR <001d> fsm.c:275 lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Deallocated 20170606183005666 DVLR <001d> vlr_lu_fsm.c:700 vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE 20170606183005666 DMM <0002> vlr_lu_fsm.c:692 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED 20170606183005666 DMM <0002> subscr_conn.c:77 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU 20170606183005666 DMM <0002> subscr_conn.c:84 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
The connection to the phone is now classified as valid and usable.
20170606183005668 DMM <0002> subscr_conn.co:132 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
Why is there a 'Received Event SUBSCR_CONN_E_BUMP'?
A "bump" event triggers a query whether any jobs are still pending for a connection, like delivering an SMS or somesuch. Typically after a LU there is nothing left to do. The phone is attached but idle:
20170606183005668 DMM <0002> subscr_conn.c:168 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn 20170606183005668 DMM <0002> subscr_conn.c:169 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED 20170606183005668 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
Indeed nothing left to do, connection is discarded, phone is subscribed and waiting for any events that would create a new connection.
So everything looks good from these logs. Cannot tell why this procedure would repeat over and over? Does it?
~N
On 6. Jun 2017, at 19:25, Neels Hofmeyr nhofmeyr@sysmocom.de wrote:
So everything looks good from these logs. Cannot tell why this procedure would repeat over and over? Does it?
Is a TMSI assigned? What is the TMSI?
@Lin: Please make a trace of two/three loops and attach it to the mail.
holger
Thanks for the quick reply.
Is a TMSI assigned? What is the TMSI?
just fond TMSI at osmo-hnbw's terminal:(0x0 not looks good )
<0001> hnbgw_hnbap.c:386 HNB-REGISTER-REQ from
000295-0000120574@ap.ipaccess.com <0000> context_map.c:139 Running context mapper garbage collection <0000> context_map.c:139 Running context mapper garbage collection <0000> context_map.c:139 Running context mapper garbage collection <0001> hnbap_decoder.c:759 Decoding message UERegisterRequestIEs (hnbap_decoder.c:759) <0001> hnbgw_hnbap.c:436 UE-REGISTER-REQ ID_type=1 imsi=901700000014922 cause=1
*<0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922, tmsi 0x0*<0000> rua_decoder.c:21 Decoding message RUA_ConnectIEs (rua_decoder.c:21) <0003> hnbgw_rua.c:310 RUA Connect.req(ctx=0x17, normal) <0000> context_map.c:83 Creating new Mapping RUA CTX 0xa67da0/23 <-> SCU Conn ID 0xa669e0/1000 <0002> sua.c:506 Received SCCP User Primitive (N-CONNECTrequest) <0002> sua.c:254 (1000) state chg IDLE->CONN_PEND_OUT <0002> sua.c:160 sua_link_send(01 00 08 01 00 00 00 84 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 03 00 08 00 02 00 07 01 16 00 08 00 00 00 00 01 0b 00 52 00 13 40 4a 00 00 06 00 03 40 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 10 40 18 17 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 00 4f 40 03 00 00 17 00 56 40 05 09 f1 07 00 17 00 00 )
more infomation of osmo-hnbg's terminal:
<0005> telnet_interface.c:95 telnet at 127.0.0.1 2323
<0003> hnbgw_cn.c:384 New hnbgw_cnlink 0x1f9a9e0 (gw 0x1f4a1c0): 127.0.0.1 14001 CS <0003> hnbgw_cn.c:384 New hnbgw_cnlink 0x1f9b8a0 (gw 0x1f4a1c0): 127.0.0.1 14001 PS <0000> hnbgw.c:524 Listening for Iuh at 192.168.31.147 29169 <0000> context_map.c:139 Running context mapper garbage collection <0001> hnbap_decoder.c:305 Decoding message HNBRegisterRequestIEs (hnbap_decoder.c:305) <0001> hnbgw_hnbap.c:386 HNB-REGISTER-REQ from 000295-0000120574@ap.ipaccess.com <0000> context_map.c:139 Running context mapper garbage collection <0000> context_map.c:139 Running context mapper garbage collection <0000> context_map.c:139 Running context mapper garbage collection <0000> context_map.c:139 Running context mapper garbage collection <0001> hnbap_decoder.c:759 Decoding message UERegisterRequestIEs (hnbap_decoder.c:759) <0001> hnbgw_hnbap.c:436 UE-REGISTER-REQ ID_type=1 imsi=901700000014922 cause=1 <0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922, tmsi 0x0 <0000> rua_decoder.c:21 Decoding message RUA_ConnectIEs (rua_decoder.c:21) <0003> hnbgw_rua.c:310 RUA Connect.req(ctx=0x17, normal) <0000> context_map.c:83 Creating new Mapping RUA CTX 0x1f9bda0/23 <-> SCU Conn ID 0x1f9a9e0/1000 <0002> sua.c:506 Received SCCP User Primitive (N-CONNECTrequest) <0002> sua.c:254 (1000) state chg IDLE->CONN_PEND_OUT <0002> sua.c:160 sua_link_send(01 00 08 01 00 00 00 84 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 03 00 08 00 02 00 07 01 16 00 08 00 00 00 00 01 0b 00 52 00 13 40 4a 00 00 06 00 03 40 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 10 40 18 17 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 00 4f 40 03 00 00 17 00 56 40 05 09 f1 07 00 17 00 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:2) <0002> sua.c:254 (1000) state chg CONN_PEND_OUT->ACTIVE <0000> hnbgw_cn.c:337 sccp_sap_up(N-CONNECTconfirm) <0000> hnbgw_cn.c:269 handle_cn_conn_conf() conn_id=1000 <0000> hnbgw_cn.c:271 handle_cn_conn_conf() called_addr=0.0.0.0 <0000> hnbgw_cn.c:273 handle_cn_conn_conf() calling_addr=0.0.0.0 <0000> hnbgw_cn.c:275 handle_cn_conn_conf() responding_addr=0.0.0.0 <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 78 bytes <0000> rua_decoder.c:21 Decoding message RUA_ConnectIEs (rua_decoder.c:21) <0003> hnbgw_rua.c:310 RUA Connect.req(ctx=0x17, normal) <0000> context_map.c:83 Creating new Mapping RUA CTX 0x1f9bda0/23 <-> SCU Conn ID 0x1f9b8a0/1000 <0002> sua.c:506 Received SCCP User Primitive (N-CONNECTrequest) <0002> sua.c:254 (1000) state chg IDLE->CONN_PEND_OUT <0002> sua.c:160 sua_link_send(01 00 08 01 00 00 00 b0 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 03 00 08 00 02 00 07 01 16 00 08 00 00 00 00 01 0b 00 7e 00 13 40 76 00 00 07 00 03 40 01 80 00 0f 40 06 00 09 f1 07 28 b6 00 37 40 01 63 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 10 40 3f 3e 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 00 4f 40 03 00 00 17 00 56 40 05 09 f1 07 00 17 00 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:2) <0002> sua.c:254 (1000) state chg CONN_PEND_OUT->ACTIVE <0000> hnbgw_cn.c:337 sccp_sap_up(N-CONNECTconfirm) <0000> hnbgw_cn.c:269 handle_cn_conn_conf() conn_id=1000 <0000> hnbgw_cn.c:271 handle_cn_conn_conf() called_addr=0.0.0.0 <0000> hnbgw_cn.c:273 handle_cn_conn_conf() calling_addr=0.0.0.0 <0000> hnbgw_cn.c:275 handle_cn_conn_conf() responding_addr=0.0.0.0 <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 00 01 0b 00 1c 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 eb f4 45 4c 21 04 a9 b6 87 20 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 28 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 00 01 0b 00 10 20 06 00 08 00 00 01 00 06 00 01 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 44 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 37 bytes <0000> rua_decoder.c:121 Decoding message RUA_DisconnectIEs (rua_decoder.c:121) <0003> hnbgw_rua.c:340 RUA Disconnect.req(ctx=0x17,cause=radio(normal)) <0002> sua.c:506 Received SCCP User Primitive (N-DISCONNECTrequest) <0002> sua.c:254 (1000) state chg ACTIVE->DISCONN_PEND <0002> sua.c:470 About to send the SUA RELRE <0002> sua.c:160 sua_link_send(01 00 08 04 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 00 01 04 00 08 00 00 03 e8 01 06 00 08 00 00 00 00 01 0b 00 0b 20 01 00 03 00 00 00 00 ) <0000> context_map.c:139 Running context mapper garbage collection <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 84 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 00 01 0b 00 69 00 14 40 61 00 00 04 00 10 40 3f 3e 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 37 40 01 63 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 00 00 ) <0000> rua_decoder.c:21 Decoding message RUA_ConnectIEs (rua_decoder.c:21) <0003> hnbgw_rua.c:310 RUA Connect.req(ctx=0x17, normal) <0002> sua.c:506 Received SCCP User Primitive (N-CONNECTrequest) <0002> sua.c:254 (1000) state chg IDLE->CONN_PEND_OUT <0002> sua.c:160 sua_link_send(01 00 08 01 00 00 00 84 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 03 00 08 00 02 00 07 01 16 00 08 00 00 00 00 01 0b 00 52 00 13 40 4a 00 00 06 00 03 40 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 10 40 18 17 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 00 4f 40 03 00 00 17 00 56 40 05 09 f1 07 00 17 00 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:2) <0002> sua.c:254 (1000) state chg CONN_PEND_OUT->ACTIVE <0000> hnbgw_cn.c:337 sccp_sap_up(N-CONNECTconfirm) <0000> hnbgw_cn.c:269 handle_cn_conn_conf() conn_id=1000 <0000> hnbgw_cn.c:271 handle_cn_conn_conf() called_addr=0.0.0.0 <0000> hnbgw_cn.c:273 handle_cn_conn_conf() calling_addr=0.0.0.0 <0000> hnbgw_cn.c:275 handle_cn_conn_conf() responding_addr=0.0.0.0 <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 78 bytes <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 01 01 0b 00 1c 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 9e 44 9d 77 21 04 8a 42 ee ac ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 28 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 01 01 0b 00 10 20 06 00 08 00 00 01 00 06 00 01 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 44 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 37 bytes <0000> rua_decoder.c:121 Decoding message RUA_DisconnectIEs (rua_decoder.c:121) <0003> hnbgw_rua.c:340 RUA Disconnect.req(ctx=0x17,cause=radio(normal)) <0002> sua.c:506 Received SCCP User Primitive (N-DISCONNECTrequest) <0002> sua.c:254 (1000) state chg ACTIVE->DISCONN_PEND <0002> sua.c:470 About to send the SUA RELRE <0002> sua.c:160 sua_link_send(01 00 08 04 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 01 01 04 00 08 00 00 03 e8 01 06 00 08 00 00 00 00 01 0b 00 0b 20 01 00 03 00 00 00 00 ) <0000> context_map.c:139 Running context mapper garbage collection <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 84 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 00 01 0b 00 69 00 14 40 61 00 00 04 00 10 40 3f 3e 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 37 40 01 63 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 00 00 ) <0000> rua_decoder.c:21 Decoding message RUA_ConnectIEs (rua_decoder.c:21) <0003> hnbgw_rua.c:310 RUA Connect.req(ctx=0x17, normal) <0002> sua.c:506 Received SCCP User Primitive (N-CONNECTrequest) <0002> sua.c:254 (1000) state chg IDLE->CONN_PEND_OUT <0002> sua.c:160 sua_link_send(01 00 08 01 00 00 00 84 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 03 00 08 00 02 00 07 01 16 00 08 00 00 00 00 01 0b 00 52 00 13 40 4a 00 00 06 00 03 40 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 3a 40 08 00 09 f1 07 ff ff ff ff 00 10 40 18 17 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 00 4f 40 03 00 00 17 00 56 40 05 09 f1 07 00 17 00 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:2) <0002> sua.c:254 (1000) state chg CONN_PEND_OUT->ACTIVE <0000> hnbgw_cn.c:337 sccp_sap_up(N-CONNECTconfirm) <0000> hnbgw_cn.c:269 handle_cn_conn_conf() conn_id=1000 <0000> hnbgw_cn.c:271 handle_cn_conn_conf() called_addr=0.0.0.0 <0000> hnbgw_cn.c:273 handle_cn_conn_conf() calling_addr=0.0.0.0 <0000> hnbgw_cn.c:275 handle_cn_conn_conf() responding_addr=0.0.0.0 <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 78 bytes <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 02 01 0b 00 1c 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 e5 d3 56 43 21 04 98 c6 f8 13 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0000> rua_decoder.c:307 Decoding message RUA_DirectTransferIEs (rua_decoder.c:307) <0003> hnbgw_rua.c:386 RUA Data.req(ctx=0x17) <0002> sua.c:506 Received SCCP User Primitive (N-DATArequest) <0002> sua.c:160 sua_link_send(01 00 08 08 00 00 00 28 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 02 01 0b 00 10 20 06 00 08 00 00 01 00 06 00 01 00 ) <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 44 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 58 bytes <0002> sua.c:1410 sua_cli_read_cb() rx <0002> sua.c:1146 Received SUA Message (8:8) <0000> hnbgw_cn.c:337 sccp_sap_up(N-DATAindication) <0003> hnbgw_rua.c:113 transmitting RUA (cn=cs) payload of 37 bytes <0000> rua_decoder.c:121 Decoding message RUA_DisconnectIEs (rua_decoder.c:121) <0003> hnbgw_rua.c:340 RUA Disconnect.req(ctx=0x17,cause=radio(normal)) <0002> sua.c:506 Received SCCP User Primitive (N-DISCONNECTrequest) <0002> sua.c:254 (1000) state chg ACTIVE->DISCONN_PEND <0002> sua.c:470 About to send the SUA RELRE <0002> sua.c:160 sua_link_send(01 00 08 04 00 00 00 34 00 06 00 08 00 00 00 00 01 05 00 08 00 00 00 02 01 04 00 08 00 00 03 e8 01 06 00 08 00 00 00 00 01 0b 00 0b 20 01 00 03 00 00 00 00 )
Information of osmo-hlr's terminal:
20170607111159419 DDB <0001> db.c:121 SQlite3 compiled with 'SYSTEM_MALLOC'
20170607111159419 DDB <0001> db.c:121 SQlite3 compiled with 'TEMP_STORE=1' 20170607111159419 DDB <0001> db.c:121 SQlite3 compiled with 'THREADSAFE=1' 20170607111159419 DDB <0001> db.c:130 Unable to set SQlite3 SQL statement log callback 20170607111159422 DLCTRL <000b> control_if.c:789 CTRL at 127.0.0.1 4259 20170607111212128 DLINP <0006> input/ipa.c:263 accept()ed new link from 127.0.0.1 to port 2222 20170607111212128 DLGSUP <000e> gsup_server.c:273 New GSUP client 127.0.0.1:37150 (IND=0) 20170607111212174 DLINP <0006> input/ipa.c:387 connected read/write 20170607111212174 DLINP <0006> input/ipa.c:338 message received 20170607111212174 DLGSUP <000e> gsup_server.c:180 CCM Callback 20170607111212174 DLGSUP <000e> gsup_server.c:136 0: MSC-00-00-00-00-00-00 20170607111212174 DLGSUP <000e> gsup_server.c:139 0: 4d 53 43 2d 30 30 2d 30 30 2d 30 30 2d 30 30 2d 30 30 2d 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 1: MSC-00-00-00-00-00-00 20170607111212174 DLGSUP <000e> gsup_server.c:139 1: 4d 53 43 2d 30 30 2d 30 30 2d 30 30 2d 30 30 2d 30 30 2d 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 2: 00:00:00:00:00:00 20170607111212174 DLGSUP <000e> gsup_server.c:139 2: 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 3: 00:00:00:00:00:00 20170607111212174 DLGSUP <000e> gsup_server.c:139 3: 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 4: 00:00:00:00:00:00 20170607111212174 DLGSUP <000e> gsup_server.c:139 4: 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 5: 00:00:00:00:00:00 20170607111212174 DLGSUP <000e> gsup_server.c:139 5: 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 7: 00:00:00:00:00:00 20170607111212174 DLGSUP <000e> gsup_server.c:139 7: 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 3a 30 30 00 00 20170607111212174 DLGSUP <000e> gsup_server.c:136 8: 0/0/0 20170607111212174 DLGSUP <000e> gsup_server.c:139 8: 30 2f 30 2f 30 00 00 20170607111212174 DLINP <0006> input/ipa.c:387 connected read/write 20170607111212174 DLINP <0006> input/ipa.c:338 message received 20170607111212174 DLINP <0006> input/ipa.c:387 connected read/write 20170607111212174 DLINP <0006> input/ipa.c:338 message received 20170607111232178 DLINP <0006> input/ipa.c:387 connected read/write 20170607111232178 DLINP <0006> input/ipa.c:338 message received 20170607111252181 DLINP <0006> input/ipa.c:387 connected read/write 20170607111252181 DLINP <0006> input/ipa.c:338 message received 20170607111312182 DLINP <0006> input/ipa.c:387 connected read/write 20170607111312182 DLINP <0006> input/ipa.c:338 message received 20170607111332185 DLINP <0006> input/ipa.c:387 connected read/write 20170607111332185 DLINP <0006> input/ipa.c:338 message received 20170607111352190 DLINP <0006> input/ipa.c:387 connected read/write 20170607111352190 DLINP <0006> input/ipa.c:338 message received 20170607111412191 DLINP <0006> input/ipa.c:387 connected read/write 20170607111412191 DLINP <0006> input/ipa.c:338 message received 20170607111412656 DLINP <0006> input/ipa.c:387 connected read/write 20170607111412656 DLINP <0006> input/ipa.c:338 message received 20170607111412656 DAUC <0003> db_auc.c:132 901700000014922: No 2G Auth Data 20170607111412656 DAUC <0003> db_auc.c:213 901700000014922: Calling to generate 5 vectors 20170607111412657 DAUC <0003> auc.c:94 Computing 5 auth vectors: 3G only (2G derived from 3G keys) 20170607111412657 DAUC <0003> auc.c:96 3G: k = 391b2415c07960489e95b8252d6891f2 20170607111412657 DAUC <0003> auc.c:99 3G: opc = a5eebf53f188b2ecec18b859f9cf5580 20170607111412658 DAUC <0003> auc.c:101 3G: for sqn ind 0, previous sqn was 1120 20170607111412658 DAUC <0003> auc.c:113 vector [0]: rand = 290b278eb6e75a9b24fb3b7429e95cb7 20170607111412658 DAUC <0003> auc.c:137 vector [0]: sqn = 1152 20170607111412658 DAUC <0003> auc.c:139 vector [0]: autn = 7c95667233b700001b73c31408df68fb 20170607111412658 DAUC <0003> auc.c:140 vector [0]: ck = 47bb3655ac0629fec010770793df18d4 20170607111412658 DAUC <0003> auc.c:141 vector [0]: ik = 4d399f123a1b076ef101e7917eed0583 20170607111412659 DAUC <0003> auc.c:142 vector [0]: res = 182cf6be6f989d490000000000000000 20170607111412659 DAUC <0003> auc.c:143 vector [0]: res_len = 8 20170607111412659 DAUC <0003> auc.c:147 vector [0]: kc = 3b9339d17b2f33c7 20170607111412659 DAUC <0003> auc.c:148 vector [0]: sres = 77b46bf7 20170607111412659 DAUC <0003> auc.c:149 vector [0]: auth_types = 0x3 20170607111412659 DAUC <0003> auc.c:113 vector [1]: rand = 186da8712a3f88c5aff10237fe90ea4c 20170607111412659 DAUC <0003> auc.c:137 vector [1]: sqn = 1184 20170607111412659 DAUC <0003> auc.c:139 vector [1]: autn = c2710a1dbca200008976bba9ce298421 20170607111412659 DAUC <0003> auc.c:140 vector [1]: ck = 563e4709816f7ef2ca4710545618dad2 20170607111412659 DAUC <0003> auc.c:141 vector [1]: ik = e06a9d0be16b41f46e391a22abaae180 20170607111412659 DAUC <0003> auc.c:142 vector [1]: res = 075ae0614ba2aba00000000000000000 20170607111412659 DAUC <0003> auc.c:143 vector [1]: res_len = 8 20170607111412659 DAUC <0003> auc.c:147 vector [1]: kc = 122ad0749db60454 20170607111412659 DAUC <0003> auc.c:148 vector [1]: sres = 4cf84bc1 20170607111412659 DAUC <0003> auc.c:149 vector [1]: auth_types = 0x3 20170607111412660 DAUC <0003> auc.c:113 vector [2]: rand = 51771b9b3e5abd58695212ba5f6ca671 20170607111412661 DAUC <0003> auc.c:137 vector [2]: sqn = 1216 20170607111412661 DAUC <0003> auc.c:139 vector [2]: autn = c63f8b297caa00006196230e87e206d2 20170607111412661 DAUC <0003> auc.c:140 vector [2]: ck = b23561961fb11061f81eb77663a298e7 20170607111412661 DAUC <0003> auc.c:141 vector [2]: ik = a08659c7f95ebbabe146b4f07e5d58ea 20170607111412661 DAUC <0003> auc.c:142 vector [2]: res = bd280358a90242960000000000000000 20170607111412661 DAUC <0003> auc.c:143 vector [2]: res_len = 8 20170607111412661 DAUC <0003> auc.c:147 vector [2]: kc = 0beb3bd7fb106bc7 20170607111412661 DAUC <0003> auc.c:148 vector [2]: sres = 142a41ce 20170607111412661 DAUC <0003> auc.c:149 vector [2]: auth_types = 0x3 20170607111412661 DAUC <0003> auc.c:113 vector [3]: rand = 16dd6cc60a08c61911cd883acc3a1798 20170607111412661 DAUC <0003> auc.c:137 vector [3]: sqn = 1248 20170607111412661 DAUC <0003> auc.c:139 vector [3]: autn = c8e9d51a3afe0000841b2b7099686e74 20170607111412661 DAUC <0003> auc.c:140 vector [3]: ck = 1545e8a0784bf1d758481b6458184ae2 20170607111412662 DAUC <0003> auc.c:141 vector [3]: ik = ab1b0f90e950c8c6a0a69833073abe29 20170607111412662 DAUC <0003> auc.c:142 vector [3]: res = 3ac465b434a83d920000000000000000 20170607111412662 DAUC <0003> auc.c:143 vector [3]: res_len = 8 20170607111412662 DAUC <0003> auc.c:147 vector [3]: kc = 46b06467ce39cdda 20170607111412662 DAUC <0003> auc.c:148 vector [3]: sres = 0e6c5826 20170607111412662 DAUC <0003> auc.c:149 vector [3]: auth_types = 0x3 20170607111412662 DAUC <0003> auc.c:113 vector [4]: rand = 35efb31811ae05eaad714917cf47e36b 20170607111412662 DAUC <0003> auc.c:137 vector [4]: sqn = 1280 20170607111412662 DAUC <0003> auc.c:139 vector [4]: autn = fca3d2b6002d000007849341c354ad86 20170607111412662 DAUC <0003> auc.c:140 vector [4]: ck = f6e8d9fbef692fd189d1be5b0a0b9a4e 20170607111412663 DAUC <0003> auc.c:141 vector [4]: ik = 431b11384acf193873f2295eabe06c65 20170607111412663 DAUC <0003> auc.c:142 vector [4]: res = 895122651358edcf0000000000000000 20170607111412663 DAUC <0003> auc.c:143 vector [4]: res_len = 8 20170607111412663 DAUC <0003> auc.c:147 vector [4]: kc = 4fd05fc6044dc0c2 20170607111412663 DAUC <0003> auc.c:148 vector [4]: sres = 9a09cfaa 20170607111412663 DAUC <0003> auc.c:149 vector [4]: auth_types = 0x3 20170607111412663 DAUC <0003> db_auc.c:222 901700000014922: Generated 5 vectors 20170607111412663 DAUC <0003> db_auc.c:227 901700000014922: Updating SQN=1280 in DB 20170607111412666 DLINP <0006> input/ipa.c:387 connected read/write 20170607111412666 DLINP <0006> input/ipa.c:366 sending data 20170607111412667 DLINP <0006> input/ipa.c:387 connected read/write 20170607111412667 DLINP <0006> input/ipa.c:366 sending data 20170607111413200 DLINP <0006> input/ipa.c:387 connected read/write 20170607111413200 DLINP <0006> input/ipa.c:338 message received 20170607111413200 DAUC <0003> db_auc.c:132 901700000014922: No 2G Auth Data 20170607111413200 DAUC <0003> db_auc.c:213 901700000014922: Calling to generate 5 vectors 20170607111413200 DAUC <0003> auc.c:94 Computing 5 auth vectors: 3G only (2G derived from 3G keys), with AUTS resync 20170607111413200 DAUC <0003> auc.c:96 3G: k = 391b2415c07960489e95b8252d6891f2 20170607111413200 DAUC <0003> auc.c:99 3G: opc = a5eebf53f188b2ecec18b859f9cf5580 20170607111413200 DAUC <0003> auc.c:101 3G: for sqn ind 0, previous sqn was 1280 20170607111413200 DAUC <0003> auc.c:113 vector [0]: rand = cf9812f4bbc3c790bf44fd9113a7ba43 20170607111413200 DAUC <0003> auc.c:122 vector [0]: resync: auts = 97be1c1a6065138ef453cf3339d4 20170607111413200 DAUC <0003> auc.c:124 vector [0]: resync: rand_auts = 290b278eb6e75a9b24fb3b7429e95cb7 20170607111413201 DAUC <0003> auc.c:137 vector [0]: sqn = 1632 20170607111413201 DAUC <0003> auc.c:139 vector [0]: autn = 29a7a580b3750000e3b863d44b4d284c 20170607111413201 DAUC <0003> auc.c:140 vector [0]: ck = 0f1845cdc17567ec2f9a3d9f9fddf557 20170607111413201 DAUC <0003> auc.c:141 vector [0]: ik = 0535fb7ba013c2695d5d2dc8149ddb2f 20170607111413201 DAUC <0003> auc.c:142 vector [0]: res = 5eecdce81488a78a0000000000000000 20170607111413201 DAUC <0003> auc.c:143 vector [0]: res_len = 8 20170607111413201 DAUC <0003> auc.c:147 vector [0]: kc = 78eaaee1ea268bfd 20170607111413201 DAUC <0003> auc.c:148 vector [0]: sres = 4a647b62 20170607111413201 DAUC <0003> auc.c:149 vector [0]: auth_types = 0x3 20170607111413201 DAUC <0003> auc.c:113 vector [1]: rand = 8106dd5bcd141db96401d17e5aa960ed 20170607111413201 DAUC <0003> auc.c:137 vector [1]: sqn = 1664 20170607111413201 DAUC <0003> auc.c:139 vector [1]: autn = 411360a06a71000004f4b5034857c3f5 20170607111413201 DAUC <0003> auc.c:140 vector [1]: ck = 734241fc87a2f22ef176b48ad660f729 20170607111413201 DAUC <0003> auc.c:141 vector [1]: ik = 786836d05d74c64d4c1f41b69bf704d2 20170607111413201 DAUC <0003> auc.c:142 vector [1]: res = c6fa36f4d713eb8d0000000000000000 20170607111413201 DAUC <0003> auc.c:143 vector [1]: res_len = 8 20170607111413201 DAUC <0003> auc.c:147 vector [1]: kc = b64382109741c798 20170607111413201 DAUC <0003> auc.c:148 vector [1]: sres = 11e9dd79 20170607111413201 DAUC <0003> auc.c:149 vector [1]: auth_types = 0x3 20170607111413201 DAUC <0003> auc.c:113 vector [2]: rand = 5fde1572c3b22f2c706469c42c4ecd4d 20170607111413201 DAUC <0003> auc.c:137 vector [2]: sqn = 1696 20170607111413201 DAUC <0003> auc.c:139 vector [2]: autn = f978984c431500001cf507b50c5c75cd 20170607111413201 DAUC <0003> auc.c:140 vector [2]: ck = 95feed87ffd50147a2a659eb46da6505 20170607111413201 DAUC <0003> auc.c:141 vector [2]: ik = 4cb0b22594be10a2d6a6c41fdcbe1f04 20170607111413201 DAUC <0003> auc.c:142 vector [2]: res = 55fbe73d8d5848cd0000000000000000 20170607111413201 DAUC <0003> auc.c:143 vector [2]: res_len = 8 20170607111413201 DAUC <0003> auc.c:147 vector [2]: kc = ad4ec256f10f6be4 20170607111413201 DAUC <0003> auc.c:148 vector [2]: sres = d8a3aff0 20170607111413201 DAUC <0003> auc.c:149 vector [2]: auth_types = 0x3 20170607111413201 DAUC <0003> auc.c:113 vector [3]: rand = 76f2ed2dec6cd2d278cdce8baff6830f 20170607111413201 DAUC <0003> auc.c:137 vector [3]: sqn = 1728 20170607111413201 DAUC <0003> auc.c:139 vector [3]: autn = c941e4394e8100004895877c9ce5690e 20170607111413201 DAUC <0003> auc.c:140 vector [3]: ck = 24f560a505e6a9f604f50d435d2185f7 20170607111413201 DAUC <0003> auc.c:141 vector [3]: ik = e1fd4fc66b6666dc48762d54d0353103 20170607111413201 DAUC <0003> auc.c:142 vector [3]: res = b813fb6b2f3c35170000000000000000 20170607111413201 DAUC <0003> auc.c:143 vector [3]: res_len = 8 20170607111413201 DAUC <0003> auc.c:147 vector [3]: kc = 898b0f74e3947bde 20170607111413201 DAUC <0003> auc.c:148 vector [3]: sres = 972fce7c 20170607111413201 DAUC <0003> auc.c:149 vector [3]: auth_types = 0x3 20170607111413201 DAUC <0003> auc.c:113 vector [4]: rand = c06a0678c8c1dc7f8022aa2114e0ebd8 20170607111413201 DAUC <0003> auc.c:137 vector [4]: sqn = 1760 20170607111413201 DAUC <0003> auc.c:139 vector [4]: autn = d8040bdc675e000058d87e4b146cc15d 20170607111413201 DAUC <0003> auc.c:140 vector [4]: ck = 40e4c154fad0783526f5ffd843cf696c 20170607111413201 DAUC <0003> auc.c:141 vector [4]: ik = bc13071980796eb3be6a1e9f8061f648 20170607111413201 DAUC <0003> auc.c:142 vector [4]: res = a740f8619e68f2ac0000000000000000 20170607111413201 DAUC <0003> auc.c:143 vector [4]: res_len = 8 20170607111413201 DAUC <0003> auc.c:147 vector [4]: kc = 6468270ab90789a2 20170607111413201 DAUC <0003> auc.c:148 vector [4]: sres = 39280acd 20170607111413201 DAUC <0003> auc.c:149 vector [4]: auth_types = 0x3 20170607111413201 DAUC <0003> db_auc.c:222 901700000014922: Generated 5 vectors 20170607111413202 DAUC <0003> db_auc.c:227 901700000014922: Updating SQN=1760 in DB 20170607111413204 DLINP <0006> input/ipa.c:387 connected read/write 20170607111413204 DLINP <0006> input/ipa.c:366 sending data 20170607111413204 DLINP <0006> input/ipa.c:387 connected read/write 20170607111413204 DLINP <0006> input/ipa.c:366 sending data 20170607111414858 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414858 DLINP <0006> input/ipa.c:338 message received 20170607111414858 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170607111414858 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED -> ISD SENT 20170607111414858 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414858 DLINP <0006> input/ipa.c:366 sending data 20170607111414858 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414858 DLINP <0006> input/ipa.c:366 sending data 20170607111414860 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414860 DLINP <0006> input/ipa.c:338 message received 20170607111414860 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414860 DLINP <0006> input/ipa.c:366 sending data 20170607111414860 DLINP <0006> input/ipa.c:387 connected read/write 20170607111414860 DLINP <0006> input/ipa.c:366 sending data 20170607111431715 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431715 DLINP <0006> input/ipa.c:338 message received 20170607111431715 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170607111431715 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED -> ISD SENT 20170607111431715 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431715 DLINP <0006> input/ipa.c:366 sending data 20170607111431715 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431715 DLINP <0006> input/ipa.c:366 sending data 20170607111431715 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431715 DLINP <0006> input/ipa.c:338 message received 20170607111431716 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431716 DLINP <0006> input/ipa.c:366 sending data 20170607111431716 DLINP <0006> input/ipa.c:387 connected read/write 20170607111431716 DLINP <0006> input/ipa.c:366 sending data 20170607111432192 DLINP <0006> input/ipa.c:387 connected read/write 20170607111432192 DLINP <0006> input/ipa.c:338 message received 20170607111448222 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448222 DLINP <0006> input/ipa.c:338 message received 20170607111448222 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170607111448222 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED -> ISD SENT 20170607111448222 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448222 DLINP <0006> input/ipa.c:366 sending data 20170607111448222 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448222 DLINP <0006> input/ipa.c:366 sending data 20170607111448223 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448223 DLINP <0006> input/ipa.c:338 message received 20170607111448223 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448223 DLINP <0006> input/ipa.c:366 sending data 20170607111448224 DLINP <0006> input/ipa.c:387 connected read/write 20170607111448224 DLINP <0006> input/ipa.c:366 sending data 20170607111452193 DLINP <0006> input/ipa.c:387 connected read/write 20170607111452193 DLINP <0006> input/ipa.c:338 message received 20170607111504691 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504691 DLINP <0006> input/ipa.c:338 message received 20170607111504691 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU RECEIVED 20170607111504691 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED -> ISD SENT 20170607111504691 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504691 DLINP <0006> input/ipa.c:366 sending data 20170607111504691 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504691 DLINP <0006> input/ipa.c:366 sending data 20170607111504694 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504694 DLINP <0006> input/ipa.c:338 message received 20170607111504694 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504694 DLINP <0006> input/ipa.c:366 sending data 20170607111504694 DLINP <0006> input/ipa.c:387 connected read/write 20170607111504694 DLINP <0006> input/ipa.c:366 sending data 20170607111512194 DLINP <0006> input/ipa.c:387 connected read/write 20170607111512195 DLINP <0006> input/ipa.c:338 message received 20170607111532197 DLINP <0006> input/ipa.c:387 connected read/write 20170607111532197 DLINP <0006> input/ipa.c:338 message received 20170607111552203 DLINP <0006> input/ipa.c:387 connected read/write 20170607111552203 DLINP <0006> input/ipa.c:338 message received 20170607111612204 DLINP <0006> input/ipa.c:387 connected read/write 20170607111612205 DLINP <0006> input/ipa.c:338 message received 20170607111632207 DLINP <0006> input/ipa.c:387 connected read/write 20170607111632207 DLINP <0006> input/ipa.c:338 message received 20170607111652212 DLINP <0006> input/ipa.c:387 connected read/write 20170607111652212 DLINP <0006> input/ipa.c:338 message received 20170607111712213 DLINP <0006> input/ipa.c:387 connected read/write 20170607111712213 DLINP <0006> input/ipa.c:338 message received 20170607111732214 DLINP <0006> input/ipa.c:387 connected read/write 20170607111732214 DLINP <0006> input/ipa.c:338 message received 20170607111752219 DLINP <0006> input/ipa.c:387 connected read/write 20170607111752219 DLINP <0006> input/ipa.c:338 message received 20170607111812220 DLINP <0006> input/ipa.c:387 connected read/write 20170607111812220 DLINP <0006> input/ipa.c:338 message received 20170607111832225 DLINP <0006> input/ipa.c:387 connected read/write 20170607111832226 DLINP <0006> input/ipa.c:338 message received 20170607111852231 DLINP <0006> input/ipa.c:387 connected read/write 20170607111852231 DLINP <0006> input/ipa.c:338 message received 20170607111912231 DLINP <0006> input/ipa.c:387 connected read/write 20170607111912231 DLINP <0006> input/ipa.c:338 message received 20170607111932232 DLINP <0006> input/ipa.c:387 connected read/write 20170607111932232 DLINP <0006> input/ipa.c:338 message received 20170607111952237 DLINP <0006> input/ipa.c:387 connected read/write 20170607111952238 DLINP <0006> input/ipa.c:338 message received 20170607112012237 DLINP <0006> input/ipa.c:387 connected read/write 20170607112012237 DLINP <0006> input/ipa.c:338 message received 20170607112032242 DLINP <0006> input/ipa.c:387 connected read/write 20170607112032242 DLINP <0006> input/ipa.c:338 message received 20170607112052244 DLINP <0006> input/ipa.c:387 connected read/write 20170607112052244 DLINP <0006> input/ipa.c:338 message received 20170607112112244 DLINP <0006> input/ipa.c:387 connected read/write 20170607112112245 DLINP <0006> input/ipa.c:338 message received 20170607112132250 DLINP <0006> input/ipa.c:387 connected read/write 20170607112132250 DLINP <0006> input/ipa.c:338 message received 20170607112152252 DLINP <0006> input/ipa.c:387 connected read/write 20170607112152253 DLINP <0006> input/ipa.c:338 message received 20170607112212253 DLINP <0006> input/ipa.c:387 connected read/write 20170607112212253 DLINP <0006> input/ipa.c:338 message received 20170607112232258 DLINP <0006> input/ipa.c:387 connected read/write 20170607112232258 DLINP <0006> input/ipa.c:338 message received 20170607112252263 DLINP <0006> input/ipa.c:387 connected read/write 20170607112252263 DLINP <0006> input/ipa.c:338 message received 20170607112312265 DLINP <0006> input/ipa.c:387 connected read/write 20170607112312265 DLINP <0006> input/ipa.c:338 message received
Information of osmo-msc's terminal:
20170607113302784 DMNCC <0006> msc_main.c:397 Using internal MNCC handler.
20170607113302784 DLGLOBAL <001f> telnet_interface.c:95 telnet at 127.0.0.1 4254 20170607113302784 DSMPP <0017> smpp_smsc.c:978 SMPP at 0.0.0.0 2775 20170607113302785 DLGSUP <0029> gsup_client.c:76 GSUP connecting to 127.0.0.1:2222 20170607113302788 DLSMS <0025> sms_queue.c:252 Attempting to send 20 SMS 20170607113302789 DLSMS <0025> sms_queue.c:236 SMS queue: no SMS to be sent 20170607113302789 DLSMS <0025> sms_queue.c:263 Sending SMS done (0 attempted) 20170607113302789 DLSMS <0025> sms_queue.c:319 SMSqueue added 0 messages in 0 rounds 20170607113302789 DMGCP <000b> mgcpgw_client.c:369 MGCP GW connection: 0.0.0.0:0 -> 192.168.31.147:2427 20170607113302789 DLINP <0021> input/ipa.c:129 connection done. 20170607113302789 DLGSUP <0029> gsup_client.c:134 GSUP link to 127.0.0.1:2222 UP 20170607113302789 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113302789 DLINP <0021> input/ipa.c:136 connected read 20170607113302789 DLINP <0021> input/ipa.c:54 message received 20170607113302789 DLINP <0021> input/ipaccess.c:706 received ID get 20170607113302789 DLINP <0021> input/ipaccess.c:641 tag 8: 0/0/0 20170607113302789 DLINP <0021> input/ipaccess.c:641 tag 7: 00:00:00:00:00:00 20170607113302789 DLINP <0021> input/ipaccess.c:641 tag 2: 00:00:00:00:00:00 20170607113302789 DLINP <0021> input/ipaccess.c:641 tag 3: 00:00:00:00:00:00 20170607113302790 DLINP <0021> input/ipaccess.c:641 tag 4: 00:00:00:00:00:00 20170607113302790 DLINP <0021> input/ipaccess.c:641 tag 5: 00:00:00:00:00:00 20170607113302790 DLINP <0021> input/ipaccess.c:641 tag 1: MSC-00-00-00-00-00-00 20170607113302790 DLINP <0021> input/ipaccess.c:641 tag 0: MSC-00-00-00-00-00-00 20170607113302790 DLINP <0021> input/ipa.c:140 connected write 20170607113302790 DLINP <0021> input/ipa.c:90 sending data 20170607113302790 DLINP <0021> input/ipa.c:140 connected write 20170607113302790 DLINP <0021> input/ipa.c:90 sending data 20170607113302790 DLINP <0021> input/ipa.c:136 connected read 20170607113302790 DLINP <0021> input/ipa.c:54 message received 20170607113302829 DLINP <0021> input/ipa.c:136 connected read 20170607113302829 DLINP <0021> input/ipa.c:54 message received 20170607113302829 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113312917 DLINP <0021> stream.c:553 accept()ed new link from 127.0.0.1 to port 14001 20170607113312917 DSUA <001b> sua.c:1351 New SCTP connection accepted 20170607113312917 DLINP <0021> stream.c:553 accept()ed new link from 127.0.0.1 to port 14001 20170607113312917 DSUA <001b> sua.c:1351 New SCTP connection accepted 20170607113316249 DLINP <0021> stream.c:802 connected read/write 20170607113316249 DLINP <0021> stream.c:750 message received 20170607113316249 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 148 20170607113316249 DSUA <001b> sua.c:1236 (127.0.0.1:49836<-> 127.0.0.1:14001) SUA SRV SCTP NOTIFICATION 32770 flags=0x0 20170607113316249 DSUA <001b> sua.c:1249 (127.0.0.1:49836<-> 127.0.0.1:14001) SUA SRV PEER_ADDR_CHANGE 20170607113316761 DLINP <0021> stream.c:802 connected read/write 20170607113316761 DLINP <0021> stream.c:750 message received 20170607113316761 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 148 20170607113316761 DSUA <001b> sua.c:1236 (127.0.0.1:38893<-> 127.0.0.1:14001) SUA SRV SCTP NOTIFICATION 32770 flags=0x0 20170607113316761 DSUA <001b> sua.c:1249 (127.0.0.1:38893<-> 127.0.0.1:14001) SUA SRV PEER_ADDR_CHANGE 20170607113322794 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113322794 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113322794 DLINP <0021> input/ipa.c:140 connected write 20170607113322794 DLINP <0021> input/ipa.c:90 sending data 20170607113322794 DLINP <0021> input/ipa.c:140 connected write 20170607113322794 DLINP <0021> input/ipa.c:90 sending data 20170607113322794 DLINP <0021> input/ipa.c:136 connected read 20170607113322794 DLINP <0021> input/ipa.c:54 message received 20170607113322794 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113342797 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113342797 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113342797 DLINP <0021> input/ipa.c:140 connected write 20170607113342797 DLINP <0021> input/ipa.c:90 sending data 20170607113342797 DLINP <0021> input/ipa.c:140 connected write 20170607113342797 DLINP <0021> input/ipa.c:90 sending data 20170607113342798 DLINP <0021> input/ipa.c:136 connected read 20170607113342798 DLINP <0021> input/ipa.c:54 message received 20170607113342798 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113402797 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113402797 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113402798 DLINP <0021> input/ipa.c:140 connected write 20170607113402798 DLINP <0021> input/ipa.c:90 sending data 20170607113402798 DLINP <0021> input/ipa.c:140 connected write 20170607113402798 DLINP <0021> input/ipa.c:90 sending data 20170607113402798 DLINP <0021> input/ipa.c:136 connected read 20170607113402798 DLINP <0021> input/ipa.c:54 message received 20170607113402798 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113422801 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113422801 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113422801 DLINP <0021> input/ipa.c:140 connected write 20170607113422801 DLINP <0021> input/ipa.c:90 sending data 20170607113422801 DLINP <0021> input/ipa.c:140 connected write 20170607113422801 DLINP <0021> input/ipa.c:90 sending data 20170607113422801 DLINP <0021> input/ipa.c:136 connected read 20170607113422801 DLINP <0021> input/ipa.c:54 message received 20170607113422801 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113442807 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113442807 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113442807 DLINP <0021> input/ipa.c:140 connected write 20170607113442807 DLINP <0021> input/ipa.c:90 sending data 20170607113442807 DLINP <0021> input/ipa.c:140 connected write 20170607113442807 DLINP <0021> input/ipa.c:90 sending data 20170607113442808 DLINP <0021> input/ipa.c:136 connected read 20170607113442808 DLINP <0021> input/ipa.c:54 message received 20170607113442808 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113502807 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113502807 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113502808 DLINP <0021> input/ipa.c:140 connected write 20170607113502808 DLINP <0021> input/ipa.c:90 sending data 20170607113502808 DLINP <0021> input/ipa.c:140 connected write 20170607113502808 DLINP <0021> input/ipa.c:90 sending data 20170607113502808 DLINP <0021> input/ipa.c:136 connected read 20170607113502808 DLINP <0021> input/ipa.c:54 message received 20170607113502808 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113522814 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113522814 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113522814 DLINP <0021> input/ipa.c:140 connected write 20170607113522814 DLINP <0021> input/ipa.c:90 sending data 20170607113522814 DLINP <0021> input/ipa.c:140 connected write 20170607113522814 DLINP <0021> input/ipa.c:90 sending data 20170607113522814 DLINP <0021> input/ipa.c:136 connected read 20170607113522814 DLINP <0021> input/ipa.c:54 message received 20170607113522815 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113524298 DLINP <0021> stream.c:802 connected read/write 20170607113524298 DLINP <0021> stream.c:750 message received 20170607113524299 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 132 20170607113524299 DSUA <001b> sua.c:1146 Received SUA Message (8:1) 20170607113524299 DSUA <001b> sua.c:659 sua_parse_addr(IEI=259) (4) 00 02 00 07 20170607113524299 DSUA <001b> sua.c:254 (0) state chg IDLE->CONN_PEND_IN 20170607113524299 DRANAP <001a> iu.c:721 sccp_sap_up(N-CONNECTindication) 20170607113524299 DRANAP <001a> iu.c:730 N-CONNECT.ind(X->0) 20170607113524299 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-CONNECTresponse) 20170607113524299 DSUA <001b> sua.c:254 (0) state chg CONN_PEND_IN->ACTIVE 20170607113524299 DSUA <001b> sua.c:160 sua_link_send(01 00 08 02 00 00 00 30 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 05 00 08 00 00 03 e8 01 04 00 08 00 00 00 00 01 16 00 08 00 00 00 00 ) 20170607113524299 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Initial UE Message) 20170607113524299 DRLL <0000> ranap_decoder.c:2641 Decoding message RANAP_InitialUE_MessageIEs (ranap_decoder.c:2641) 20170607113524299 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=19) 20170607113524299 DRANAP <001a> iu.c:143 New RNC 23 (LAC=10422 RAC=0) 20170607113524299 DIUCS <001e> msc_main.c:321 got IuCS message 23 bytes: 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 20170607113524299 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 0 20170607113524299 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 0 20170607113524299 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113524299 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 0 20170607113524299 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7fde0, conn_id 0 20170607113524299 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) 20170607113524299 DMM <0002> fsm.c:231 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_INIT}: Allocated 20170607113524299 DMM <0002> subscr_conn.c:344 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START 20170607113524299 DMM <0002> subscr_conn.c:66 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW 20170607113524299 DMM <0002> gsm_04_08.c:300 LOCATION UPDATING REQUEST: MI(IMSI)=901700000014922 type=NORMAL 20170607113524299 DMM <0002> gsm_04_08.c:345 LU/new-LAC: 65534/10422 20170607113524299 DVLR <001d> fsm.c:231 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: Allocated 20170607113524299 DVLR <001d> fsm.c:261 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000014922)[0x1ca52f0] 20170607113524299 DVLR <001d> vlr_lu_fsm.c:1409 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: rev=R99 net=UTRAN Auth+Ciph 20170607113524299 DVLR <001d> vlr_lu_fsm.c:1415 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA 20170607113524299 DVLR <001d> vlr.c:375 set IMSI on subscriber; IMSI=901700000014922 id=901700000014922 20170607113524299 DVLR <001d> vlr.c:334 New subscr, IMSI: 901700000014922 20170607113524299 DVLR <001d> vlr_lu_fsm.c:838 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1() 20170607113524299 DVLR <001d> vlr_lu_fsm.c:845 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH 20170607113524299 DVLR <001d> fsm.c:231 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH}: Allocated 20170607113524299 DVLR <001d> fsm.c:261 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524299 DVLR <001d> vlr_auth_fsm.c:602 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START 20170607113524299 DVLR <001d> vlr.c:145 GSUP tx: 08010809710000004129f2 20170607113524299 DVLR <001d> vlr_auth_fsm.c:296 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI 20170607113524299 DMM <0002> osmo_msc.c:54 IMSI:901700000014922: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113524299 DLINP <0021> input/ipa.c:140 connected write 20170607113524299 DLINP <0021> input/ipa.c:90 sending data 20170607113524299 DLINP <0021> stream.c:802 connected read/write 20170607113524299 DLINP <0021> stream.c:767 sending data 20170607113524299 DLINP <0021> input/ipa.c:140 connected write 20170607113524299 DLINP <0021> input/ipa.c:90 sending data 20170607113524299 DLINP <0021> stream.c:802 connected read/write 20170607113524299 DLINP <0021> stream.c:767 sending data 20170607113524303 DLINP <0021> input/ipa.c:136 connected read 20170607113524303 DLINP <0021> input/ipa.c:54 message received 20170607113524303 DVLR <001d> vlr.c:790 GSUP rx 511: 0a010809710000004129f20362201097c08af4e489069463f235833423f4c421044242c26c2208a3f15f998fdd0c2e23103b5c23f342ebdf6baa28f57ca6c7f6dc24100c3fdfbb39bd6a703eba56ad524c4fe925100fa4f283610800008a131af6576e60862708ebf4454ca9b68720036220101595ffdaf06a27d0cafe39ec7ee356de2104140673db2208deb018c1ac2bd0c2231054f32afbf3bcadd134fd7a9e3533e7342410cd70db2bbefe823473ce938fd45a18132510667c8dd1067d0000e24b9b22574e0eb427089e449d778a42eeac036220101cbff4654712b2bffdaeea373dfd28d421047d15ae5022084b5a6368a43e0a732310567c6861094a593cc77ffb3ac8d3131c241035c0f4cda8548274ef9904fecdf3c22725100075752ddbce0000d91fcdc34c0acc542708e5d3564398c6f8130362201047c9683572d789e926efa28e6289382c2104dc4330502208e05c6d596967b2a5231047070ff418f32b475866ada3bbf1e8da2410af999826ec713e2250a4572826144f1a2510eceea9c9d287000084db5b0aba42d2f02708379065e7ebd355b703622010763a869e57e93d7a3f44276d1bd3e92a2104efd82f9722086323a24b7b8af130231054ce33598044bf0ae77a0b6dd230744d241055b9bae4eb996bed852e209bc267519a2510286790e0320d0000ef1a670fad7ab4b327081f3e0555f0e62ac2 20170607113524303 DVLR <001d> vlr.c:608 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK 20170607113524303 DVLR <001d> vlr.c:588 SUBSCR(IMSI:901700000014922) Received 5 auth tuples 20170607113524303 DVLR <001d> vlr_auth_fsm.c:352 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP 20170607113524303 DVLR <001d> vlr_auth_fsm.c:263 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 20170607113524303 DMM <0002> gsm_04_08.c:552 -> AUTH REQ (rand = 97c08af4e489069463f235833423f4c4) 20170607113524303 DMM <0002> gsm_04_08.c:554 AUTH REQ (autn = 0fa4f283610800008a131af6576e6086) 20170607113524303 DMSC <000a> msc_ifaces.c:44 msc_tx 37 bytes to IMSI:901700000014922 via RAN_UTRAN_IU 20170607113524303 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 0) 20170607113524303 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113524303 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 54 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 3a 00 14 00 32 00 00 02 00 10 40 26 25 05 12 00 97 c0 8a f4 e4 89 06 94 63 f2 35 83 34 23 f4 c4 20 10 0f a4 f2 83 61 08 00 00 8a 13 1a f6 57 6e 60 86 00 3b 40 01 00 00 00 ) 20170607113524303 DLINP <0021> stream.c:802 connected read/write 20170607113524303 DLINP <0021> stream.c:767 sending data 20170607113524303 DLINP <0021> stream.c:802 connected read/write 20170607113524303 DLINP <0021> stream.c:767 sending data 20170607113524483 DLINP <0021> stream.c:802 connected read/write 20170607113524483 DLINP <0021> stream.c:750 message received 20170607113524483 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 176 20170607113524483 DSUA <001b> sua.c:1146 Received SUA Message (8:1) 20170607113524483 DSUA <001b> sua.c:659 sua_parse_addr(IEI=259) (4) 00 02 00 07 20170607113524483 DSUA <001b> sua.c:254 (0) state chg IDLE->CONN_PEND_IN 20170607113524483 DRANAP <001a> iu.c:721 sccp_sap_up(N-CONNECTindication) 20170607113524483 DRANAP <001a> iu.c:730 N-CONNECT.ind(X->0) 20170607113524483 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-CONNECTresponse) 20170607113524483 DSUA <001b> sua.c:254 (0) state chg CONN_PEND_IN->ACTIVE 20170607113524483 DSUA <001b> sua.c:160 sua_link_send(01 00 08 02 00 00 00 30 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 05 00 08 00 00 03 e8 01 04 00 08 00 00 00 00 01 16 00 08 00 00 00 00 ) 20170607113524483 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Initial UE Message) 20170607113524483 DRLL <0000> ranap_decoder.c:2641 Decoding message RANAP_InitialUE_MessageIEs (ranap_decoder.c:2641) 20170607113524483 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=19) 20170607113524483 DRANAP <001a> iu.c:164 RNC 23 changes its details: LAC=10422 RAC=0 --> LAC=10422 RAC=99 20170607113524483 DRANAP <001a> iu.c:171 RNC 23 on new link (LAC=10422 RAC=99) 20170607113524483 DIUCS <001e> msc_main.c:321 got IuCS message 62 bytes: 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 20170607113524483 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 99 20170607113524483 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7e310, conn_id 0 20170607113524483 DIUCS <001e> iucs.c:76 0: IMSI:901700000014922 Iu link 0x1c7fde0, conn_id 0 20170607113524483 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113524483 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7e310, conn_id 0 20170607113524483 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7e310, conn_id 0 20170607113524483 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_PDISC_MM_GPRS:0x01 (0x8:0x1) 20170607113524483 DRLL <0000> gsm_04_08.c:3602 subscr unknown: Message not permitted for initial conn: GSM48_PDISC_MM_GPRS:0x01 20170607113524483 DRLL <0000> osmo_msc.c:217 Freeing subscriber connection with NULL subscriber 20170607113524483 DLINP <0021> stream.c:802 connected read/write 20170607113524483 DLINP <0021> stream.c:767 sending data 20170607113524483 DLINP <0021> stream.c:802 connected read/write 20170607113524484 DLINP <0021> stream.c:767 sending data 20170607113524721 DLINP <0021> stream.c:802 connected read/write 20170607113524721 DLINP <0021> stream.c:750 message received 20170607113524721 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113524721 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113524721 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113524721 DRANAP <001a> iu.c:754 N-DATA.ind(0, 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 eb f4 45 4c 21 04 a9 b6 87 20 ) 20170607113524721 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Direct Transfer) 20170607113524722 DRLL <0000> ranap_decoder.c:3197 Decoding message RANAP_DirectTransferIEs (ranap_decoder.c:3197) 20170607113524722 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=20) 20170607113524722 DIUCS <001e> msc_main.c:321 got IuCS message 12 bytes: 05 54 eb f4 45 4c 21 04 a9 b6 87 20 20170607113524722 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 0 20170607113524722 DIUCS <001e> iucs.c:76 0: IMSI:901700000014922 Iu link 0x1c7fde0, conn_id 0 20170607113524722 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113524722 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 0 20170607113524722 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14) 20170607113524722 DMM <0002> gsm_04_08.c:908 IMSI:901700000014922: MM R99 AUTHENTICATION RESPONSE (res = ebf4454ca9b68720) 20170607113524722 DVLR <001d> vlr.c:1043 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP 20170607113524722 DVLR <001d> vlr_auth_fsm.c:142 SUBSCR(IMSI:901700000014922) received res: eb f4 45 4c a9 b6 87 20 20170607113524722 DVLR <001d> vlr_auth_fsm.c:179 SUBSCR(IMSI:901700000014922) AUTH established UMTS security context 20170607113524722 DVLR <001d> vlr_auth_fsm.c:231 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result VLR_AUTH_RES_PASSED 20170607113524722 DVLR <001d> vlr_auth_fsm.c:235 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED 20170607113524722 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113524722 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524722 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_AUTHENTICATED}: Freeing instance 20170607113524722 DVLR <001d> fsm.c:275 VLR_Authenticate(901700000014922)[0x1ca8940]{VLR_SUB_AS_AUTHENTICATED}: Deallocated 20170607113524722 DVLR <001d> vlr_auth_fsm.c:240 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES 20170607113524722 DVLR <001d> vlr_lu_fsm.c:812 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() 20170607113524722 DMM <0002> gsm_04_08.c:3775 -> SECURITY MODE CONTROL IMSI:901700000014922 20170607113524722 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113524722 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 06 00 1e 00 00 02 00 0c 00 12 08 08 3b 5c 23 f3 42 eb df 6b aa 28 f5 7c a6 c7 f6 dc 00 4b 00 01 40 00 00 ) 20170607113524722 DVLR <001d> vlr_lu_fsm.c:830 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH 20170607113524722 DMM <0002> osmo_msc.c:54 IMSI:901700000014922: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113524722 DLINP <0021> stream.c:802 connected read/write 20170607113524722 DLINP <0021> stream.c:767 sending data 20170607113524722 DLINP <0021> stream.c:802 connected read/write 20170607113524722 DLINP <0021> stream.c:767 sending data 20170607113524949 DLINP <0021> stream.c:802 connected read/write 20170607113524950 DLINP <0021> stream.c:750 message received 20170607113524950 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 40 20170607113524950 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113524950 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113524950 DRANAP <001a> iu.c:754 N-DATA.ind(0, 20 06 00 08 00 00 01 00 06 00 01 00 ) 20170607113524950 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Security Mode Control) 20170607113524950 DRLL <0000> ranap_decoder.c:4315 Decoding message RANAP_SecurityModeCompleteIEs (ranap_decoder.c:4315) 20170607113524950 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=6) 20170607113524950 DIUCS <001e> msc_main.c:335 got IuCS event 1: IU_EVENT_SECURITY_MODE_COMPLETE 20170607113524950 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 0 20170607113524950 DIUCS <001e> iucs.c:76 0: IMSI:901700000014922 Iu link 0x1c7fde0, conn_id 0 20170607113524950 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113524950 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 0 20170607113524950 DIUCS <001e> iucs_ranap.c:95 IuCS security mode complete for IMSI:901700000014922 20170607113524950 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE IMSI:901700000014922 20170607113524950 DVLR <001d> vlr.c:1052 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_CIPH}: Received Event VLR_ULA_E_CIPH_RES 20170607113524950 DVLR <001d> vlr_lu_fsm.c:780 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph() 20170607113524950 DIUCS <001e> msc_ifaces.c:116 IMSI:901700000014922: tx CommonID 901700000014922 20170607113524950 DRANAP <001a> iu.c:258 Transmitting RANAP CommonID (SUA link 0x1c7fde0 conn_id 0) 20170607113524951 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113524951 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 30 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 18 00 0f 40 10 00 00 01 00 17 40 09 50 09 71 00 00 00 41 29 f2 ) 20170607113524951 DVLR <001d> vlr_lu_fsm.c:743 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4() 20170607113524951 DVLR <001d> vlr_lu_fsm.c:752 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD 20170607113524951 DVLR <001d> fsm.c:231 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_INIT}: Allocated 20170607113524951 DVLR <001d> fsm.c:261 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524951 DVLR <001d> vlr_lu_fsm.c:164 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START 20170607113524951 DVLR <001d> vlr.c:145 GSUP tx: 04010809710000004129f2 20170607113524951 DVLR <001d> vlr_lu_fsm.c:81 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 20170607113524951 DLINP <0021> input/ipa.c:140 connected write 20170607113524951 DLINP <0021> input/ipa.c:90 sending data 20170607113524951 DLINP <0021> stream.c:802 connected read/write 20170607113524951 DLINP <0021> stream.c:767 sending data 20170607113524951 DLINP <0021> input/ipa.c:140 connected write 20170607113524951 DLINP <0021> input/ipa.c:90 sending data 20170607113524951 DLINP <0021> stream.c:802 connected read/write 20170607113524951 DLINP <0021> stream.c:767 sending data 20170607113524952 DLINP <0021> input/ipa.c:136 connected read 20170607113524952 DLINP <0021> input/ipa.c:54 message received 20170607113524952 DVLR <001d> vlr.c:790 GSUP rx 16: 10010809710000004129f208030233f3 20170607113524952 DVLR <001d> vlr.c:646 IMSI:901700000014922 has MSISDN:333 20170607113524952 DVLR <001d> vlr.c:145 GSUP tx: 12010809710000004129f2 20170607113524952 DLINP <0021> input/ipa.c:140 connected write 20170607113524952 DLINP <0021> input/ipa.c:90 sending data 20170607113524952 DLINP <0021> input/ipa.c:140 connected write 20170607113524952 DLINP <0021> input/ipa.c:90 sending data 20170607113524952 DLINP <0021> input/ipa.c:136 connected read 20170607113524953 DLINP <0021> input/ipa.c:54 message received 20170607113524953 DVLR <001d> vlr.c:790 GSUP rx 11: 06010809710000004129f2 20170607113524953 DVLR <001d> vlr.c:736 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES 20170607113524953 DVLR <001d> vlr_lu_fsm.c:1145 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK 20170607113524953 DVLR <001d> vlr_lu_fsm.c:103 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE 20170607113524953 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113524953 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524953 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_DONE}: Freeing instance 20170607113524953 DVLR <001d> fsm.c:275 upd_hlr_vlr_fsm(901700000014922)[0x1c7e580]{UPD_HLR_VLR_S_DONE}: Deallocated 20170607113524953 DVLR <001d> vlr_lu_fsm.c:104 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL 20170607113524953 DVLR <001d> vlr_lu_fsm.c:1153 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL 20170607113524953 DVLR <001d> fsm.c:231 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_INIT}: Allocated 20170607113524953 DVLR <001d> fsm.c:261 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524953 DVLR <001d> vlr_lu_fsm.c:725 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START 20170607113524953 DVLR <001d> vlr_lu_fsm.c:385 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES 20170607113524953 DVLR <001d> fsm.c:231 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_INIT}: Allocated 20170607113524953 DVLR <001d> fsm.c:261 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000014922)[0x1c7e580] 20170607113524953 DVLR <001d> vlr_lu_fsm.c:267 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START 20170607113524953 DVLR <001d> vlr_lu_fsm.c:200 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE 20170607113524953 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113524953 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000014922)[0x1c7e580] 20170607113524953 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_DONE}: Freeing instance 20170607113524953 DVLR <001d> fsm.c:275 sub_pres_vlr_fsm(901700000014922)[0x1c81590]{SUB_PRES_VLR_S_DONE}: Deallocated 20170607113524953 DVLR <001d> vlr_lu_fsm.c:201 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL 20170607113524953 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE ACCEPT 20170607113524953 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333 via RAN_UTRAN_IU 20170607113524953 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 0) 20170607113524953 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113524953 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e 00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22 00 3b 40 01 00 00 00 ) 20170607113524953 DVLR <001d> vlr_lu_fsm.c:321 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE 20170607113524953 DVLR <001d> vlr_lu_fsm.c:355 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS 20170607113524953 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113524953 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca8250] 20170607113524953 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_DONE}: Freeing instance 20170607113524953 DVLR <001d> fsm.c:275 lu_compl_vlr_fsm(901700000014922)[0x1c7e580]{LU_COMPL_VLR_S_DONE}: Deallocated 20170607113524953 DVLR <001d> vlr_lu_fsm.c:700 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE 20170607113524953 DMM <0002> vlr_lu_fsm.c:692 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED 20170607113524953 DMM <0002> subscr_conn.c:77 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU 20170607113524953 DMM <0002> subscr_conn.c:84 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED 20170607113524956 DMM <0002> subscr_conn.c:132 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 20170607113524956 DMM <0002> subscr_conn.c:168 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn 20170607113524956 DMM <0002> subscr_conn.c:169 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED 20170607113524956 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113524956 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113524956 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000014922)[0x1ca52f0] 20170607113524956 DVLR <001d> vlr_lu_fsm.c:1342 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT 20170607113524956 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_DONE}: Freeing instance 20170607113524956 DVLR <001d> fsm.c:275 vlr_lu_fsm(901700000014922)[0x1ca8250]{VLR_ULA_S_DONE}: Deallocated 20170607113524956 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113524956 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 2c 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 11 00 01 00 09 00 00 01 00 04 40 02 07 80 00 00 00 ) 20170607113524956 DRLL <0000> osmo_msc.c:211 subscr MSISDN:333: Freeing subscriber connection 20170607113524956 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_RELEASED}: Freeing instance 20170607113524956 DMM <0002> fsm.c:275 Subscr_Conn(901700000014922)[0x1ca52f0]{SUBSCR_CONN_S_RELEASED}: Deallocated 20170607113524956 DLINP <0021> stream.c:802 connected read/write 20170607113524956 DLINP <0021> stream.c:767 sending data 20170607113524956 DLINP <0021> stream.c:802 connected read/write 20170607113524956 DLINP <0021> stream.c:767 sending data 20170607113524956 DLINP <0021> stream.c:802 connected read/write 20170607113524956 DLINP <0021> stream.c:767 sending data 20170607113525164 DLINP <0021> stream.c:802 connected read/write 20170607113525164 DLINP <0021> stream.c:750 message received 20170607113525164 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113525164 DSUA <001b> sua.c:1146 Received SUA Message (8:4) 20170607113525164 DRANAP <001a> iu.c:721 sccp_sap_up(N-DISCONNECTindication) 20170607113525164 DRANAP <001a> iu.c:747 N-DISCONNECT.ind(0) 20170607113525164 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Iu Release) 20170607113525164 DRLL <0000> ranap_decoder.c:4055 Decoding message RANAP_Iu_ReleaseCompleteIEs (ranap_decoder.c:4055) 20170607113525164 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=1) 20170607113525164 DIUCS <001e> msc_main.c:335 got IuCS event 2: IU_EVENT_IU_RELEASE 20170607113525165 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 0 20170607113525165 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113525165 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 0 20170607113525165 DRANAP <001a> iucs_ranap.c:81 Cannot find subscriber for IU event 2 20170607113525165 DRANAP <001a> iu.c:504 Iu Release event: Iu Event callback returned -1 20170607113525165 DRANAP <001a> iu.c:537 Error in cn_ranap_handle_co (-1) 20170607113525165 DSUA <001b> sua.c:254 (0) state chg ACTIVE->IDLE 20170607113539843 DLINP <0021> stream.c:802 connected read/write 20170607113539844 DLINP <0021> stream.c:750 message received 20170607113539844 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 132 20170607113539844 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113539844 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113539844 DRANAP <001a> iu.c:754 N-DATA.ind(0, 00 14 40 61 00 00 04 00 10 40 3f 3e 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 37 40 01 63 00 3a 40 08 00 09 f1 07 ff ff ff ff ) 20170607113539844 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Direct Transfer) 20170607113539844 DRLL <0000> ranap_decoder.c:3197 Decoding message RANAP_DirectTransferIEs (ranap_decoder.c:3197) 20170607113539844 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=20) 20170607113539844 DIUCS <001e> msc_main.c:321 got IuCS message 62 bytes: 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 20170607113539844 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 99 20170607113539844 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7e310, conn_id 0 20170607113539844 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113539844 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7e310, conn_id 0 20170607113539844 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7e310, conn_id 0 20170607113539844 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_PDISC_MM_GPRS:0x01 (0x8:0x1) 20170607113539844 DRLL <0000> gsm_04_08.c:3602 subscr unknown: Message not permitted for initial conn: GSM48_PDISC_MM_GPRS:0x01 20170607113539844 DRLL <0000> osmo_msc.c:217 Freeing subscriber connection with NULL subscriber 20170607113540615 DLINP <0021> stream.c:802 connected read/write 20170607113540616 DLINP <0021> stream.c:750 message received 20170607113540616 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 132 20170607113540616 DSUA <001b> sua.c:1146 Received SUA Message (8:1) 20170607113540616 DSUA <001b> sua.c:659 sua_parse_addr(IEI=259) (4) 00 02 00 07 20170607113540616 DSUA <001b> sua.c:254 (1) state chg IDLE->CONN_PEND_IN 20170607113540616 DRANAP <001a> iu.c:721 sccp_sap_up(N-CONNECTindication) 20170607113540616 DRANAP <001a> iu.c:730 N-CONNECT.ind(X->1) 20170607113540616 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-CONNECTresponse) 20170607113540616 DSUA <001b> sua.c:254 (1) state chg CONN_PEND_IN->ACTIVE 20170607113540616 DSUA <001b> sua.c:160 sua_link_send(01 00 08 02 00 00 00 30 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 05 00 08 00 00 03 e8 01 04 00 08 00 00 00 01 01 16 00 08 00 00 00 00 ) 20170607113540616 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Initial UE Message) 20170607113540616 DRLL <0000> ranap_decoder.c:2641 Decoding message RANAP_InitialUE_MessageIEs (ranap_decoder.c:2641) 20170607113540616 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=19) 20170607113540616 DRANAP <001a> iu.c:164 RNC 23 changes its details: LAC=10422 RAC=99 --> LAC=10422 RAC=0 20170607113540616 DRANAP <001a> iu.c:171 RNC 23 on new link (LAC=10422 RAC=0) 20170607113540616 DIUCS <001e> msc_main.c:321 got IuCS message 23 bytes: 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 20170607113540616 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 0 20170607113540616 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 1 20170607113540616 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113540616 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 1 20170607113540616 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7fde0, conn_id 1 20170607113540616 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) 20170607113540616 DMM <0002> fsm.c:231 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_INIT}: Allocated 20170607113540616 DMM <0002> subscr_conn.c:344 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START 20170607113540616 DMM <0002> subscr_conn.c:66 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW 20170607113540616 DMM <0002> gsm_04_08.c:300 LOCATION UPDATING REQUEST: MI(IMSI)=901700000014922 type=NORMAL 20170607113540616 DMM <0002> gsm_04_08.c:345 LU/new-LAC: 65534/10422 20170607113540616 DVLR <001d> fsm.c:231 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: Allocated 20170607113540616 DVLR <001d> fsm.c:261 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000014922)[0x1ca5290] 20170607113540616 DVLR <001d> vlr_lu_fsm.c:1409 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: rev=R99 net=UTRAN Auth+Ciph 20170607113540616 DVLR <001d> vlr_lu_fsm.c:1415 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA 20170607113540616 DVLR <001d> vlr_lu_fsm.c:838 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1() 20170607113540616 DVLR <001d> vlr_lu_fsm.c:845 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH 20170607113540616 DVLR <001d> fsm.c:231 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_NEEDS_AUTH}: Allocated 20170607113540617 DVLR <001d> fsm.c:261 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113540617 DVLR <001d> vlr_auth_fsm.c:602 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START 20170607113540617 DVLR <001d> vlr_auth_fsm.c:300 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP 20170607113540617 DVLR <001d> vlr_auth_fsm.c:263 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 20170607113540617 DMM <0002> gsm_04_08.c:552 -> AUTH REQ (rand = 1595ffdaf06a27d0cafe39ec7ee356de) 20170607113540617 DMM <0002> gsm_04_08.c:554 AUTH REQ (autn = 667c8dd1067d0000e24b9b22574e0eb4) 20170607113540617 DMSC <000a> msc_ifaces.c:44 msc_tx 37 bytes to MSISDN:333 via RAN_UTRAN_IU 20170607113540617 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 1) 20170607113540617 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113540617 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 54 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 3a 00 14 00 32 00 00 02 00 10 40 26 25 05 12 01 15 95 ff da f0 6a 27 d0 ca fe 39 ec 7e e3 56 de 20 10 66 7c 8d d1 06 7d 00 00 e2 4b 9b 22 57 4e 0e b4 00 3b 40 01 00 00 00 ) 20170607113540617 DMM <0002> osmo_msc.c:54 MSISDN:333: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113540617 DLINP <0021> stream.c:802 connected read/write 20170607113540617 DLINP <0021> stream.c:767 sending data 20170607113540617 DLINP <0021> stream.c:802 connected read/write 20170607113540617 DLINP <0021> stream.c:767 sending data 20170607113540617 DLINP <0021> stream.c:802 connected read/write 20170607113540617 DLINP <0021> stream.c:767 sending data 20170607113541234 DLINP <0021> stream.c:802 connected read/write 20170607113541234 DLINP <0021> stream.c:750 message received 20170607113541234 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113541234 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113541234 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113541234 DRANAP <001a> iu.c:754 N-DATA.ind(1, 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 9e 44 9d 77 21 04 8a 42 ee ac ) 20170607113541234 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Direct Transfer) 20170607113541234 DRLL <0000> ranap_decoder.c:3197 Decoding message RANAP_DirectTransferIEs (ranap_decoder.c:3197) 20170607113541234 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=20) 20170607113541234 DIUCS <001e> msc_main.c:321 got IuCS message 12 bytes: 05 54 9e 44 9d 77 21 04 8a 42 ee ac 20170607113541234 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 1 20170607113541234 DIUCS <001e> iucs.c:76 0: MSISDN:333 Iu link 0x1c7fde0, conn_id 1 20170607113541234 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113541234 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 1 20170607113541234 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14) 20170607113541234 DMM <0002> gsm_04_08.c:908 MSISDN:333: MM R99 AUTHENTICATION RESPONSE (res = 9e449d778a42eeac) 20170607113541234 DVLR <001d> vlr.c:1043 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP 20170607113541234 DVLR <001d> vlr_auth_fsm.c:142 SUBSCR(MSISDN:333) received res: 9e 44 9d 77 8a 42 ee ac 20170607113541234 DVLR <001d> vlr_auth_fsm.c:179 SUBSCR(MSISDN:333) AUTH established UMTS security context 20170607113541234 DVLR <001d> vlr_auth_fsm.c:231 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result VLR_AUTH_RES_PASSED 20170607113541234 DVLR <001d> vlr_auth_fsm.c:235 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED 20170607113541234 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113541234 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113541234 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_AUTHENTICATED}: Freeing instance 20170607113541234 DVLR <001d> fsm.c:275 VLR_Authenticate(901700000014922)[0x1ca9e90]{VLR_SUB_AS_AUTHENTICATED}: Deallocated 20170607113541234 DVLR <001d> vlr_auth_fsm.c:240 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES 20170607113541235 DVLR <001d> vlr_lu_fsm.c:812 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() 20170607113541235 DMM <0002> gsm_04_08.c:3775 -> SECURITY MODE CONTROL MSISDN:333 20170607113541235 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113541235 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 06 00 1e 00 00 02 00 0c 00 12 08 08 54 f3 2a fb f3 bc ad d1 34 fd 7a 9e 35 33 e7 34 00 4b 00 01 40 00 00 ) 20170607113541235 DVLR <001d> vlr_lu_fsm.c:830 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH 20170607113541235 DMM <0002> osmo_msc.c:54 MSISDN:333: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113541235 DLINP <0021> stream.c:802 connected read/write 20170607113541235 DLINP <0021> stream.c:767 sending data 20170607113541235 DLINP <0021> stream.c:802 connected read/write 20170607113541235 DLINP <0021> stream.c:767 sending data 20170607113541471 DLINP <0021> stream.c:802 connected read/write 20170607113541471 DLINP <0021> stream.c:750 message received 20170607113541471 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 40 20170607113541471 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113541471 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113541471 DRANAP <001a> iu.c:754 N-DATA.ind(1, 20 06 00 08 00 00 01 00 06 00 01 00 ) 20170607113541471 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Security Mode Control) 20170607113541471 DRLL <0000> ranap_decoder.c:4315 Decoding message RANAP_SecurityModeCompleteIEs (ranap_decoder.c:4315) 20170607113541471 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=6) 20170607113541471 DIUCS <001e> msc_main.c:335 got IuCS event 1: IU_EVENT_SECURITY_MODE_COMPLETE 20170607113541471 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 1 20170607113541471 DIUCS <001e> iucs.c:76 0: MSISDN:333 Iu link 0x1c7fde0, conn_id 1 20170607113541471 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113541471 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 1 20170607113541471 DIUCS <001e> iucs_ranap.c:95 IuCS security mode complete for MSISDN:333 20170607113541471 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE MSISDN:333 20170607113541471 DVLR <001d> vlr.c:1052 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_CIPH}: Received Event VLR_ULA_E_CIPH_RES 20170607113541471 DVLR <001d> vlr_lu_fsm.c:780 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph() 20170607113541471 DIUCS <001e> msc_ifaces.c:116 MSISDN:333: tx CommonID 901700000014922 20170607113541471 DRANAP <001a> iu.c:258 Transmitting RANAP CommonID (SUA link 0x1c7fde0 conn_id 1) 20170607113541471 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113541471 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 30 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 18 00 0f 40 10 00 00 01 00 17 40 09 50 09 71 00 00 00 41 29 f2 ) 20170607113541471 DVLR <001d> vlr_lu_fsm.c:743 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4() 20170607113541471 DVLR <001d> vlr_lu_fsm.c:752 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD 20170607113541471 DVLR <001d> fsm.c:231 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_INIT}: Allocated 20170607113541471 DVLR <001d> fsm.c:261 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113541471 DVLR <001d> vlr_lu_fsm.c:164 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START 20170607113541471 DVLR <001d> vlr.c:145 GSUP tx: 04010809710000004129f2 20170607113541471 DVLR <001d> vlr_lu_fsm.c:81 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 20170607113541471 DLINP <0021> input/ipa.c:140 connected write 20170607113541471 DLINP <0021> input/ipa.c:90 sending data 20170607113541471 DLINP <0021> stream.c:802 connected read/write 20170607113541471 DLINP <0021> stream.c:767 sending data 20170607113541471 DLINP <0021> input/ipa.c:140 connected write 20170607113541471 DLINP <0021> input/ipa.c:90 sending data 20170607113541471 DLINP <0021> stream.c:802 connected read/write 20170607113541471 DLINP <0021> stream.c:767 sending data 20170607113541472 DLINP <0021> input/ipa.c:136 connected read 20170607113541472 DLINP <0021> input/ipa.c:54 message received 20170607113541472 DVLR <001d> vlr.c:790 GSUP rx 16: 10010809710000004129f208030233f3 20170607113541473 DVLR <001d> vlr.c:646 IMSI:901700000014922 has MSISDN:333 20170607113541473 DVLR <001d> vlr.c:145 GSUP tx: 12010809710000004129f2 20170607113541473 DLINP <0021> input/ipa.c:140 connected write 20170607113541473 DLINP <0021> input/ipa.c:90 sending data 20170607113541473 DLINP <0021> input/ipa.c:140 connected write 20170607113541473 DLINP <0021> input/ipa.c:90 sending data 20170607113541473 DLINP <0021> input/ipa.c:136 connected read 20170607113541473 DLINP <0021> input/ipa.c:54 message received 20170607113541473 DVLR <001d> vlr.c:790 GSUP rx 11: 06010809710000004129f2 20170607113541473 DVLR <001d> vlr.c:736 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES 20170607113541473 DVLR <001d> vlr_lu_fsm.c:1145 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK 20170607113541473 DVLR <001d> vlr_lu_fsm.c:103 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE 20170607113541473 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113541473 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113541473 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_DONE}: Freeing instance 20170607113541473 DVLR <001d> fsm.c:275 upd_hlr_vlr_fsm(901700000014922)[0x1ca8b20]{UPD_HLR_VLR_S_DONE}: Deallocated 20170607113541473 DVLR <001d> vlr_lu_fsm.c:104 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL 20170607113541473 DVLR <001d> vlr_lu_fsm.c:1153 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL 20170607113541473 DVLR <001d> fsm.c:231 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_INIT}: Allocated 20170607113541473 DVLR <001d> fsm.c:261 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113541473 DVLR <001d> vlr_lu_fsm.c:725 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START 20170607113541474 DVLR <001d> vlr_lu_fsm.c:385 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES 20170607113541474 DVLR <001d> fsm.c:231 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_INIT}: Allocated 20170607113541474 DVLR <001d> fsm.c:261 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000014922)[0x1c81380] 20170607113541474 DVLR <001d> vlr_lu_fsm.c:267 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START 20170607113541474 DVLR <001d> vlr_lu_fsm.c:200 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE 20170607113541474 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113541474 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000014922)[0x1c81380] 20170607113541474 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_DONE}: Freeing instance 20170607113541474 DVLR <001d> fsm.c:275 sub_pres_vlr_fsm(901700000014922)[0x1ca89c0]{SUB_PRES_VLR_S_DONE}: Deallocated 20170607113541474 DVLR <001d> vlr_lu_fsm.c:201 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL 20170607113541474 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE ACCEPT 20170607113541474 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333 via RAN_UTRAN_IU 20170607113541474 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 1) 20170607113541474 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113541474 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e 00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22 00 3b 40 01 00 00 00 ) 20170607113541474 DVLR <001d> vlr_lu_fsm.c:321 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE 20170607113541474 DVLR <001d> vlr_lu_fsm.c:355 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS 20170607113541474 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113541474 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1ca9930] 20170607113541474 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_DONE}: Freeing instance 20170607113541474 DVLR <001d> fsm.c:275 lu_compl_vlr_fsm(901700000014922)[0x1c81380]{LU_COMPL_VLR_S_DONE}: Deallocated 20170607113541474 DVLR <001d> vlr_lu_fsm.c:700 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE 20170607113541474 DMM <0002> vlr_lu_fsm.c:692 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED 20170607113541474 DMM <0002> subscr_conn.c:77 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU 20170607113541474 DMM <0002> subscr_conn.c:84 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED 20170607113541476 DMM <0002> subscr_conn.c:132 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 20170607113541476 DMM <0002> subscr_conn.c:168 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn 20170607113541476 DMM <0002> subscr_conn.c:169 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED 20170607113541476 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113541476 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113541476 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000014922)[0x1ca5290] 20170607113541477 DVLR <001d> vlr_lu_fsm.c:1342 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT 20170607113541477 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_DONE}: Freeing instance 20170607113541477 DVLR <001d> fsm.c:275 vlr_lu_fsm(901700000014922)[0x1ca9930]{VLR_ULA_S_DONE}: Deallocated 20170607113541477 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113541477 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 2c 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 11 00 01 00 09 00 00 01 00 04 40 02 07 80 00 00 00 ) 20170607113541477 DRLL <0000> osmo_msc.c:211 subscr MSISDN:333: Freeing subscriber connection 20170607113541477 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_RELEASED}: Freeing instance 20170607113541477 DMM <0002> fsm.c:275 Subscr_Conn(901700000014922)[0x1ca5290]{SUBSCR_CONN_S_RELEASED}: Deallocated 20170607113541477 DLINP <0021> stream.c:802 connected read/write 20170607113541477 DLINP <0021> stream.c:767 sending data 20170607113541477 DLINP <0021> stream.c:802 connected read/write 20170607113541477 DLINP <0021> stream.c:767 sending data 20170607113541477 DLINP <0021> stream.c:802 connected read/write 20170607113541477 DLINP <0021> stream.c:767 sending data 20170607113541687 DLINP <0021> stream.c:802 connected read/write 20170607113541687 DLINP <0021> stream.c:750 message received 20170607113541687 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113541687 DSUA <001b> sua.c:1146 Received SUA Message (8:4) 20170607113541687 DRANAP <001a> iu.c:721 sccp_sap_up(N-DISCONNECTindication) 20170607113541687 DRANAP <001a> iu.c:747 N-DISCONNECT.ind(1) 20170607113541687 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Iu Release) 20170607113541687 DRLL <0000> ranap_decoder.c:4055 Decoding message RANAP_Iu_ReleaseCompleteIEs (ranap_decoder.c:4055) 20170607113541687 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=1) 20170607113541687 DIUCS <001e> msc_main.c:335 got IuCS event 2: IU_EVENT_IU_RELEASE 20170607113541687 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 1 20170607113541687 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113541687 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 1 20170607113541687 DRANAP <001a> iucs_ranap.c:81 Cannot find subscriber for IU event 2 20170607113541687 DRANAP <001a> iu.c:504 Iu Release event: Iu Event callback returned -1 20170607113541687 DRANAP <001a> iu.c:537 Error in cn_ranap_handle_co (-1) 20170607113541687 DSUA <001b> sua.c:254 (1) state chg ACTIVE->IDLE 20170607113542816 DLGSUP <0029> gsup_client.c:244 GSUP ping callback (connected, got PONG) 20170607113542816 DLGSUP <0029> gsup_client.c:265 GSUP sending PING 20170607113542816 DLINP <0021> input/ipa.c:140 connected write 20170607113542817 DLINP <0021> input/ipa.c:90 sending data 20170607113542817 DLINP <0021> input/ipa.c:140 connected write 20170607113542817 DLINP <0021> input/ipa.c:90 sending data 20170607113542817 DLINP <0021> input/ipa.c:136 connected read 20170607113542817 DLINP <0021> input/ipa.c:54 message received 20170607113542817 DLGSUP <0029> gsup_client.c:201 GSUP receiving PONG 20170607113555085 DLINP <0021> stream.c:802 connected read/write 20170607113555085 DLINP <0021> stream.c:750 message received 20170607113555085 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 132 20170607113555085 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113555085 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113555085 DRANAP <001a> iu.c:754 N-DATA.ind(0, 00 14 40 61 00 00 04 00 10 40 3f 3e 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 00 0f 40 06 00 09 f1 07 28 b6 00 37 40 01 63 00 3a 40 08 00 09 f1 07 ff ff ff ff ) 20170607113555085 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Direct Transfer) 20170607113555085 DRLL <0000> ranap_decoder.c:3197 Decoding message RANAP_DirectTransferIEs (ranap_decoder.c:3197) 20170607113555085 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=20) 20170607113555085 DIUCS <001e> msc_main.c:321 got IuCS message 62 bytes: 08 01 03 e5 e0 34 71 0a 00 08 99 10 07 00 00 10 94 22 ff ff 00 ff fe ff 1a 19 53 43 2b 25 96 62 1e 44 00 9d d8 c6 33 10 f2 20 04 e8 c4 b1 98 87 91 00 26 17 05 58 04 e0 60 c0 40 5d 01 00 20170607113555085 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 99 20170607113555085 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7e310, conn_id 0 20170607113555085 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113555086 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7e310, conn_id 0 20170607113555086 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7e310, conn_id 0 20170607113555086 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_PDISC_MM_GPRS:0x01 (0x8:0x1) 20170607113555086 DRLL <0000> gsm_04_08.c:3602 subscr unknown: Message not permitted for initial conn: GSM48_PDISC_MM_GPRS:0x01 20170607113555086 DRLL <0000> osmo_msc.c:217 Freeing subscriber connection with NULL subscriber 20170607113557339 DLINP <0021> stream.c:802 connected read/write 20170607113557339 DLINP <0021> stream.c:750 message received 20170607113557339 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 132 20170607113557339 DSUA <001b> sua.c:1146 Received SUA Message (8:1) 20170607113557339 DSUA <001b> sua.c:659 sua_parse_addr(IEI=259) (4) 00 02 00 07 20170607113557339 DSUA <001b> sua.c:254 (2) state chg IDLE->CONN_PEND_IN 20170607113557339 DRANAP <001a> iu.c:721 sccp_sap_up(N-CONNECTindication) 20170607113557339 DRANAP <001a> iu.c:730 N-CONNECT.ind(X->2) 20170607113557339 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-CONNECTresponse) 20170607113557339 DSUA <001b> sua.c:254 (2) state chg CONN_PEND_IN->ACTIVE 20170607113557339 DSUA <001b> sua.c:160 sua_link_send(01 00 08 02 00 00 00 30 00 06 00 08 00 00 00 00 01 15 00 08 00 00 00 02 01 05 00 08 00 00 03 e8 01 04 00 08 00 00 00 02 01 16 00 08 00 00 00 00 ) 20170607113557339 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Initial UE Message) 20170607113557339 DRLL <0000> ranap_decoder.c:2641 Decoding message RANAP_InitialUE_MessageIEs (ranap_decoder.c:2641) 20170607113557339 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=19) 20170607113557339 DIUCS <001e> msc_main.c:321 got IuCS message 23 bytes: 05 08 70 09 f1 89 ff fe 57 08 99 10 07 00 00 10 94 22 33 03 57 58 a6 20170607113557339 DIUCS <001e> msc_main.c:325 got IuCS message on MNC 70 MCC 901 LAC 10422 RAC 0 20170607113557339 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 2 20170607113557340 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113557340 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 2 20170607113557340 DIUCS <001e> iucs.c:44 Allocating IuCS subscriber conn: lac 10422, link_id 0x1c7fde0, conn_id 2 20170607113557340 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8) 20170607113557340 DMM <0002> fsm.c:231 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_INIT}: Allocated 20170607113557340 DMM <0002> subscr_conn.c:344 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_INIT}: Received Event SUBSCR_CONN_E_START 20170607113557340 DMM <0002> subscr_conn.c:66 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_INIT}: state_chg to SUBSCR_CONN_S_NEW 20170607113557340 DMM <0002> gsm_04_08.c:300 LOCATION UPDATING REQUEST: MI(IMSI)=901700000014922 type=NORMAL 20170607113557340 DMM <0002> gsm_04_08.c:345 LU/new-LAC: 65534/10422 20170607113557340 DVLR <001d> fsm.c:231 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: Allocated 20170607113557340 DVLR <001d> fsm.c:261 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: is child of Subscr_Conn(901700000014922)[0x1c815d0] 20170607113557340 DVLR <001d> vlr_lu_fsm.c:1409 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: rev=R99 net=UTRAN Auth+Ciph 20170607113557340 DVLR <001d> vlr_lu_fsm.c:1415 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA 20170607113557340 DVLR <001d> vlr_lu_fsm.c:838 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1() 20170607113557340 DVLR <001d> vlr_lu_fsm.c:845 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH 20170607113557340 DVLR <001d> fsm.c:231 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_NEEDS_AUTH}: Allocated 20170607113557340 DVLR <001d> fsm.c:261 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113557340 DVLR <001d> vlr_auth_fsm.c:602 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START 20170607113557340 DVLR <001d> vlr_auth_fsm.c:300 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP 20170607113557340 DVLR <001d> vlr_auth_fsm.c:263 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 20170607113557340 DMM <0002> gsm_04_08.c:552 -> AUTH REQ (rand = 1cbff4654712b2bffdaeea373dfd28d4) 20170607113557340 DMM <0002> gsm_04_08.c:554 AUTH REQ (autn = 0075752ddbce0000d91fcdc34c0acc54) 20170607113557340 DMSC <000a> msc_ifaces.c:44 msc_tx 37 bytes to MSISDN:333 via RAN_UTRAN_IU 20170607113557340 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 2) 20170607113557340 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113557340 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 54 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 3a 00 14 00 32 00 00 02 00 10 40 26 25 05 12 02 1c bf f4 65 47 12 b2 bf fd ae ea 37 3d fd 28 d4 20 10 00 75 75 2d db ce 00 00 d9 1f cd c3 4c 0a cc 54 00 3b 40 01 00 00 00 ) 20170607113557340 DMM <0002> osmo_msc.c:54 MSISDN:333: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113557340 DLINP <0021> stream.c:802 connected read/write 20170607113557341 DLINP <0021> stream.c:767 sending data 20170607113557341 DLINP <0021> stream.c:802 connected read/write 20170607113557341 DLINP <0021> stream.c:767 sending data 20170607113557341 DLINP <0021> stream.c:802 connected read/write 20170607113557341 DLINP <0021> stream.c:767 sending data 20170607113558464 DLINP <0021> stream.c:802 connected read/write 20170607113558464 DLINP <0021> stream.c:750 message received 20170607113558465 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113558465 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113558465 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113558465 DRANAP <001a> iu.c:754 N-DATA.ind(2, 00 14 40 14 00 00 01 00 10 40 0d 0c 05 54 e5 d3 56 43 21 04 98 c6 f8 13 ) 20170607113558465 DRSL <0004> ranap_common_cn.c:43 Rx CO IM (Direct Transfer) 20170607113558465 DRLL <0000> ranap_decoder.c:3197 Decoding message RANAP_DirectTransferIEs (ranap_decoder.c:3197) 20170607113558465 DRANAP <001a> iu.c:468 handle_co(dir=1, proc=20) 20170607113558465 DIUCS <001e> msc_main.c:321 got IuCS message 12 bytes: 05 54 e5 d3 56 43 21 04 98 c6 f8 13 20170607113558465 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 2 20170607113558465 DIUCS <001e> iucs.c:76 0: MSISDN:333 Iu link 0x1c7fde0, conn_id 2 20170607113558465 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113558465 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 2 20170607113558465 DRLL <0000> gsm_04_08.c:3595 Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14) 20170607113558465 DMM <0002> gsm_04_08.c:908 MSISDN:333: MM R99 AUTHENTICATION RESPONSE (res = e5d3564398c6f813) 20170607113558465 DVLR <001d> vlr.c:1043 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP 20170607113558465 DVLR <001d> vlr_auth_fsm.c:142 SUBSCR(MSISDN:333) received res: e5 d3 56 43 98 c6 f8 13 20170607113558465 DVLR <001d> vlr_auth_fsm.c:179 SUBSCR(MSISDN:333) AUTH established UMTS security context 20170607113558465 DVLR <001d> vlr_auth_fsm.c:231 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result VLR_AUTH_RES_PASSED 20170607113558465 DVLR <001d> vlr_auth_fsm.c:235 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED 20170607113558465 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113558465 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113558465 DVLR <001d> vlr_auth_fsm.c:240 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_AUTHENTICATED}: Freeing instance 20170607113558465 DVLR <001d> fsm.c:275 VLR_Authenticate(901700000014922)[0x1caaaa0]{VLR_SUB_AS_AUTHENTICATED}: Deallocated 20170607113558465 DVLR <001d> vlr_auth_fsm.c:240 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES 20170607113558465 DVLR <001d> vlr_lu_fsm.c:812 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() 20170607113558465 DMM <0002> gsm_04_08.c:3775 -> SECURITY MODE CONTROL MSISDN:333 20170607113558465 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113558465 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 06 00 1e 00 00 02 00 0c 00 12 08 08 56 7c 68 61 09 4a 59 3c c7 7f fb 3a c8 d3 13 1c 00 4b 00 01 40 00 00 ) 20170607113558466 DVLR <001d> vlr_lu_fsm.c:830 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH 20170607113558466 DMM <0002> osmo_msc.c:54 MSISDN:333: bump: conn still being established (SUBSCR_CONN_S_NEW) 20170607113558466 DLINP <0021> stream.c:802 connected read/write 20170607113558466 DLINP <0021> stream.c:767 sending data 20170607113558466 DLINP <0021> stream.c:802 connected read/write 20170607113558466 DLINP <0021> stream.c:767 sending data 20170607113559029 DLINP <0021> stream.c:802 connected read/write 20170607113559029 DLINP <0021> stream.c:750 message received 20170607113559030 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 40 20170607113559030 DSUA <001b> sua.c:1146 Received SUA Message (8:8) 20170607113559030 DRANAP <001a> iu.c:721 sccp_sap_up(N-DATAindication) 20170607113559030 DRANAP <001a> iu.c:754 N-DATA.ind(2, 20 06 00 08 00 00 01 00 06 00 01 00 ) 20170607113559030 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Security Mode Control) 20170607113559030 DRLL <0000> ranap_decoder.c:4315 Decoding message RANAP_SecurityModeCompleteIEs (ranap_decoder.c:4315) 20170607113559031 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=6) 20170607113559031 DIUCS <001e> msc_main.c:335 got IuCS event 1: IU_EVENT_SECURITY_MODE_COMPLETE 20170607113559031 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 2 20170607113559031 DIUCS <001e> iucs.c:76 0: MSISDN:333 Iu link 0x1c7fde0, conn_id 2 20170607113559031 DIUCS <001e> iucs.c:101 subscribers registered: 1 20170607113559031 DIUCS <001e> iucs.c:122 Found IuCS subscriber for link_id 0x1c7fde0, conn_id 2 20170607113559031 DIUCS <001e> iucs_ranap.c:95 IuCS security mode complete for MSISDN:333 20170607113559031 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE MSISDN:333 20170607113559031 DVLR <001d> vlr.c:1052 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_CIPH}: Received Event VLR_ULA_E_CIPH_RES 20170607113559031 DVLR <001d> vlr_lu_fsm.c:780 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph() 20170607113559031 DIUCS <001e> msc_ifaces.c:116 MSISDN:333: tx CommonID 901700000014922 20170607113559031 DRANAP <001a> iu.c:258 Transmitting RANAP CommonID (SUA link 0x1c7fde0 conn_id 2) 20170607113559031 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113559031 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 30 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 18 00 0f 40 10 00 00 01 00 17 40 09 50 09 71 00 00 00 41 29 f2 ) 20170607113559031 DVLR <001d> vlr_lu_fsm.c:743 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4() 20170607113559031 DVLR <001d> vlr_lu_fsm.c:752 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD 20170607113559031 DVLR <001d> fsm.c:231 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_INIT}: Allocated 20170607113559031 DVLR <001d> fsm.c:261 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113559031 DVLR <001d> vlr_lu_fsm.c:164 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START 20170607113559031 DVLR <001d> vlr.c:145 GSUP tx: 04010809710000004129f2 20170607113559031 DVLR <001d> vlr_lu_fsm.c:81 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 20170607113559031 DLINP <0021> input/ipa.c:140 connected write 20170607113559031 DLINP <0021> input/ipa.c:90 sending data 20170607113559031 DLINP <0021> stream.c:802 connected read/write 20170607113559031 DLINP <0021> stream.c:767 sending data 20170607113559031 DLINP <0021> input/ipa.c:140 connected write 20170607113559032 DLINP <0021> input/ipa.c:90 sending data 20170607113559032 DLINP <0021> stream.c:802 connected read/write 20170607113559032 DLINP <0021> stream.c:767 sending data 20170607113559032 DLINP <0021> input/ipa.c:136 connected read 20170607113559032 DLINP <0021> input/ipa.c:54 message received 20170607113559032 DVLR <001d> vlr.c:790 GSUP rx 16: 10010809710000004129f208030233f3 20170607113559032 DVLR <001d> vlr.c:646 IMSI:901700000014922 has MSISDN:333 20170607113559032 DVLR <001d> vlr.c:145 GSUP tx: 12010809710000004129f2 20170607113559032 DLINP <0021> input/ipa.c:140 connected write 20170607113559032 DLINP <0021> input/ipa.c:90 sending data 20170607113559032 DLINP <0021> input/ipa.c:140 connected write 20170607113559032 DLINP <0021> input/ipa.c:90 sending data 20170607113559032 DLINP <0021> input/ipa.c:136 connected read 20170607113559032 DLINP <0021> input/ipa.c:54 message received 20170607113559032 DVLR <001d> vlr.c:790 GSUP rx 11: 06010809710000004129f2 20170607113559032 DVLR <001d> vlr.c:736 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES 20170607113559033 DVLR <001d> vlr_lu_fsm.c:1145 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK 20170607113559033 DVLR <001d> vlr_lu_fsm.c:103 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE 20170607113559033 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113559033 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113559033 DVLR <001d> vlr_lu_fsm.c:104 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_DONE}: Freeing instance 20170607113559033 DVLR <001d> fsm.c:275 upd_hlr_vlr_fsm(901700000014922)[0x1ca8940]{UPD_HLR_VLR_S_DONE}: Deallocated 20170607113559033 DVLR <001d> vlr_lu_fsm.c:104 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL 20170607113559033 DVLR <001d> vlr_lu_fsm.c:1153 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL 20170607113559033 DVLR <001d> fsm.c:231 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_INIT}: Allocated 20170607113559033 DVLR <001d> fsm.c:261 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113559033 DVLR <001d> vlr_lu_fsm.c:725 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START 20170607113559033 DVLR <001d> vlr_lu_fsm.c:385 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES 20170607113559033 DVLR <001d> fsm.c:231 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_INIT}: Allocated 20170607113559033 DVLR <001d> fsm.c:261 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(901700000014922)[0x1ca9840] 20170607113559033 DVLR <001d> vlr_lu_fsm.c:267 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START 20170607113559033 DVLR <001d> vlr_lu_fsm.c:200 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE 20170607113559033 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113559033 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(901700000014922)[0x1ca9840] 20170607113559033 DVLR <001d> vlr_lu_fsm.c:201 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_DONE}: Freeing instance 20170607113559033 DVLR <001d> fsm.c:275 sub_pres_vlr_fsm(901700000014922)[0x1caa850]{SUB_PRES_VLR_S_DONE}: Deallocated 20170607113559033 DVLR <001d> vlr_lu_fsm.c:201 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL 20170607113559033 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE ACCEPT 20170607113559033 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333 via RAN_UTRAN_IU 20170607113559033 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP DT (SUA link 0x1c7fde0 conn_id 2) 20170607113559033 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113559033 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e 00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22 00 3b 40 01 00 00 00 ) 20170607113559033 DVLR <001d> vlr_lu_fsm.c:321 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE 20170607113559033 DVLR <001d> vlr_lu_fsm.c:355 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS 20170607113559033 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113559033 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(901700000014922)[0x1c81700] 20170607113559033 DVLR <001d> vlr_lu_fsm.c:733 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_DONE}: Freeing instance 20170607113559033 DVLR <001d> fsm.c:275 lu_compl_vlr_fsm(901700000014922)[0x1ca9840]{LU_COMPL_VLR_S_DONE}: Deallocated 20170607113559033 DVLR <001d> vlr_lu_fsm.c:700 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE 20170607113559033 DMM <0002> vlr_lu_fsm.c:692 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED 20170607113559033 DMM <0002> subscr_conn.c:77 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU 20170607113559033 DMM <0002> subscr_conn.c:84 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED 20170607113559035 DMM <0002> subscr_conn.c:132 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 20170607113559035 DMM <0002> subscr_conn.c:168 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_ACCEPTED}: bump: releasing conn 20170607113559035 DMM <0002> subscr_conn.c:169 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED 20170607113559035 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) 20170607113559035 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 20170607113559035 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(901700000014922)[0x1c815d0] 20170607113559035 DVLR <001d> vlr_lu_fsm.c:1342 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT 20170607113559035 DVLR <001d> subscr_conn.c:255 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_DONE}: Freeing instance 20170607113559035 DVLR <001d> fsm.c:275 vlr_lu_fsm(901700000014922)[0x1c81700]{VLR_ULA_S_DONE}: Deallocated 20170607113559035 DSUA <001b> sua.c:506 Received SCCP User Primitive (N-DATArequest) 20170607113559035 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00 2c 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 11 00 01 00 09 00 00 01 00 04 40 02 07 80 00 00 00 ) 20170607113559035 DRLL <0000> osmo_msc.c:211 subscr MSISDN:333: Freeing subscriber connection 20170607113559035 DMM <0002> subscr_conn.c:255 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_RELEASED}: Freeing instance 20170607113559035 DMM <0002> fsm.c:275 Subscr_Conn(901700000014922)[0x1c815d0]{SUBSCR_CONN_S_RELEASED}: Deallocated 20170607113559035 DLINP <0021> stream.c:802 connected read/write 20170607113559035 DLINP <0021> stream.c:767 sending data 20170607113559035 DLINP <0021> stream.c:802 connected read/write 20170607113559035 DLINP <0021> stream.c:767 sending data 20170607113559035 DLINP <0021> stream.c:802 connected read/write 20170607113559035 DLINP <0021> stream.c:767 sending data 20170607113559644 DLINP <0021> stream.c:802 connected read/write 20170607113559645 DLINP <0021> stream.c:750 message received 20170607113559645 DSUA <001b> sua.c:1274 sua_srv_conn_cb(): sctp_recvmsg() returned 52 20170607113559645 DSUA <001b> sua.c:1146 Received SUA Message (8:4) 20170607113559645 DRANAP <001a> iu.c:721 sccp_sap_up(N-DISCONNECTindication) 20170607113559645 DRANAP <001a> iu.c:747 N-DISCONNECT.ind(2) 20170607113559645 DRSL <0004> ranap_common_cn.c:137 Rx CO SO (Iu Release) 20170607113559645 DRLL <0000> ranap_decoder.c:4055 Decoding message RANAP_Iu_ReleaseCompleteIEs (ranap_decoder.c:4055) 20170607113559645 DRANAP <001a> iu.c:468 handle_co(dir=2, proc=1) 20170607113559645 DIUCS <001e> msc_main.c:335 got IuCS event 2: IU_EVENT_IU_RELEASE 20170607113559645 DIUCS <001e> iucs.c:113 Looking for IuCS subscriber: link_id 0x1c7fde0, conn_id 2 20170607113559645 DIUCS <001e> iucs.c:101 subscribers registered: 0 20170607113559645 DIUCS <001e> iucs.c:126 No IuCS subscriber found for link_id 0x1c7fde0, conn_id 2 20170607113559645 DRANAP <001a> iucs_ranap.c:81 Cannot find subscriber for IU event 2 20170607113559645 DRANAP <001a> iu.c:504 Iu Release event: Iu Event callback returned -1 20170607113559645 DRANAP <001a> iu.c:537 Error in cn_ranap_handle_co (-1) 20170607113559645 DSUA <001b> sua.c:254 (2) state chg ACTIVE->IDLE
what should i do to fix it?
2017-06-06 21:49 GMT+08:00 Holger Freyther holger@freyther.de:
On 6. Jun 2017, at 19:25, Neels Hofmeyr nhofmeyr@sysmocom.de wrote:
So everything looks good from these logs. Cannot tell why this procedure
would
repeat over and over? Does it?
Is a TMSI assigned? What is the TMSI?
@Lin: Please make a trace of two/three loops and attach it to the mail.
holger
On 7. Jun 2017, at 10:48, 雪碧 0xroot renxianyuanqi@gmail.com wrote:
Thanks for the quick reply.
I wondered if I need to clarify but then assumed it would be obvious enough. With trace I meant packet trace to capture what is being sent between the different components.
Is a TMSI assigned? What is the TMSI?
just fond TMSI at osmo-hnbw's terminal:(0x0 not looks good )
<0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922, tmsi 0x0
the phone ME might not have a TMSI initially. Not bad.
Thank you Holger and Neels. The problem is solved now. We re-checked out the latest version and right branch of OpenBSC. The previous branch may be wrong. Now the cellphone was successfully attached.
Lin
2017-06-07 10:54 GMT+08:00 Holger Freyther holger@freyther.de:
On 7. Jun 2017, at 10:48, 雪碧 0xroot renxianyuanqi@gmail.com wrote:
Thanks for the quick reply.
I wondered if I need to clarify but then assumed it would be obvious enough. With trace I meant packet trace to capture what is being sent between the different components.
Is a TMSI assigned? What is the TMSI?
just fond TMSI at osmo-hnbw's terminal:(0x0 not looks good )
<0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922,
tmsi 0x0
the phone ME might not have a TMSI initially. Not bad.
-
Holger Freyther -
Lin HUANG -
Neels Hofmeyr -
雪碧 0xroot