Accelerate3g5 Problem in cellphone attach procedure

[雪碧 0xroot]

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 at 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 at 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 at freyther.de>:

>
> > On 6. Jun 2017, at 19:25, Neels Hofmeyr <nhofmeyr at 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
>
>
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/openbsc/attachments/20170607/16fd36f2/attachment.htm>