6 Jun
2017
6 Jun
'17
12:09 p.m.
Hello,
We met a problem during the cellphone trying to attach to the network.
The modules we ran are: Nano femtocell <- LAN -> osmo-hnbgw <--> osmo-msc
<--> osmo-hlr. The cellphone with sysmcom USIM searched the network 90170
and then tried to register in it. The authentication was passed but the
connection was released. The cellphone automatically repeated the attach
again and again, but always failed.
In the output of HLR, it seems the authentication is OK:
----------------------
20170606183004032 DAUC <0003> db_auc.c:222 901700000014922: Generated 5
vectors
20170606183004032 DAUC <0003> db_auc.c:227 901700000014922: Updating
SQN=1728 in DB
...
20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU
RECEIVED
20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED
-> ISD SENT
----------------------
But in the output of MSC:
----------------------
20170606183005665 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE
IMSI:901700000014922
...
20170606183005666 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE
ACCEPT
...
20170606183005666 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333
via RAN_UTRAN_IU
20170606183005666 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP
DT (SUA link 0xcacde0 conn_id 0)
20170606183005666 DSUA <001b> sua.c:506 Received SCCP User Primitive
(N-DATArequest)
20170606183005666 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00
40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e
00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22
00 3b 40 01 00 00 00 )
20170606183005666 DVLR <001d> vlr_lu_fsm.c:321
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}:
state_chg to LU_COMPL_VLR_S_DONE
20170606183005666 DVLR <001d> vlr_lu_fsm.c:355
vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: Received
Event VLR_ULA_E_LU_COMPL_SUCCESS
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}:
Terminating (cause = OSMO_FSM_TERM_PARENT)
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Removing
from parent vlr_lu_fsm(901700000014922)[0xcd5250]
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Freeing
instance
20170606183005666 DVLR <001d> fsm.c:275
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}:
Deallocated
20170606183005666 DVLR <001d> vlr_lu_fsm.c:700
vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg
to VLR_ULA_S_DONE
20170606183005666 DMM <0002> vlr_lu_fsm.c:692
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: Received Event
SUBSCR_CONN_E_ACCEPTED
20170606183005666 DMM <0002> subscr_conn.c:77
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}:
SUBSCR_CONN_FROM_LU
20170606183005666 DMM <0002> subscr_conn.c:84
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: state_chg to
SUBSCR_CONN_S_ACCEPTED
20170606183005668 DMM <0002> subscr_conn.c:132
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: Received
Event SUBSCR_CONN_E_BUMP
20170606183005668 DMM <0002> subscr_conn.c:168
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: bump:
releasing conn
20170606183005668 DMM <0002> subscr_conn.c:169
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: state_chg
to SUBSCR_CONN_S_RELEASED
20170606183005668 DMM <0002> subscr_conn.c:255
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_RELEASED}: Terminating
(cause = OSMO_FSM_TERM_REGULAR)
----------------------
Why is there a 'Received Event SUBSCR_CONN_E_BUMP'?
Regards
Lin
6 Jun
6 Jun
1:25 p.m.
Hi Lin,
On Tue, Jun 06, 2017 at 06:09:16PM +0800, Lin HUANG wrote:
In the output of HLR, it seems the authentication is
OK:
----------------------
20170606183004032 DAUC <0003> db_auc.c:222 901700000014922: Generated 5
vectors
20170606183004032 DAUC <0003> db_auc.c:227 901700000014922: Updating
SQN=1728 in DB
...
20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: NULL -> LU
RECEIVED
20170606183005665 DMAIN <0000> luop.c:148 LU OP state change: LU RECEIVED
-> ISD SENT
----------------------
looks good
But in the output of MSC:
----------------------
20170606183005665 DMM <0002> gsm_04_08.c:3798 <- SECURITY MODE COMPLETE
IMSI:901700000014922
...
20170606183005666 DMM <0002> gsm_04_08.c:201 -> MSISDN:333 LOCATION UPDATE
ACCEPT
...
20170606183005666 DMSC <000a> msc_ifaces.c:44 msc_tx 17 bytes to MSISDN:333
via RAN_UTRAN_IU
20170606183005666 DRANAP <001a> iu.c:391 Transmitting L3 Message as RANAP
DT (SUA link 0xcacde0 conn_id 0)
20170606183005666 DSUA <001b> sua.c:506 Received SCCP User Primitive
(N-DATArequest)
20170606183005666 DSUA <001b> sua.c:160 sua_link_send(01 00 08 08 00 00 00
40 00 06 00 08 00 00 00 00 01 05 00 08 00 00 03 e8 01 0b 00 26 00 14 00 1e
00 00 02 00 10 40 12 11 05 02 09 f1 89 28 b6 17 08 99 10 07 00 00 10 94 22
00 3b 40 01 00 00 00 )
20170606183005666 DVLR <001d> vlr_lu_fsm.c:321
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_WAIT_SUB_PRES}:
state_chg to LU_COMPL_VLR_S_DONE
20170606183005666 DVLR <001d> vlr_lu_fsm.c:355
vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: Received
Event VLR_ULA_E_LU_COMPL_SUCCESS
^ Location updating is successful at this point.
The Finite State Machine for LU is hence torn down:
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}:
Terminating (cause = OSMO_FSM_TERM_PARENT)
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Removing
from parent vlr_lu_fsm(901700000014922)[0xcd5250]
20170606183005666 DVLR <001d> vlr_lu_fsm.c:733
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}: Freeing
instance
20170606183005666 DVLR <001d> fsm.c:275
lu_compl_vlr_fsm(901700000014922)[0xcab580]{LU_COMPL_VLR_S_DONE}:
Deallocated
20170606183005666 DVLR <001d> vlr_lu_fsm.c:700
vlr_lu_fsm(901700000014922)[0xcd5250]{VLR_ULA_S_WAIT_LU_COMPL}: state_chg
to VLR_ULA_S_DONE
20170606183005666 DMM <0002> vlr_lu_fsm.c:692
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: Received Event
SUBSCR_CONN_E_ACCEPTED
20170606183005666 DMM <0002> subscr_conn.c:77
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}:
SUBSCR_CONN_FROM_LU
20170606183005666 DMM <0002> subscr_conn.c:84
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_NEW}: state_chg to
SUBSCR_CONN_S_ACCEPTED
The connection to the phone is now classified as valid and usable.
20170606183005668 DMM <0002> subscr_conn.co:132
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: Received
Event SUBSCR_CONN_E_BUMP
Why is there a 'Received Event
SUBSCR_CONN_E_BUMP'?
A "bump" event triggers a query whether any jobs are still pending for a
connection, like delivering an SMS or somesuch. Typically after a LU there is
nothing left to do. The phone is attached but idle:
20170606183005668 DMM <0002> subscr_conn.c:168
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: bump:
releasing conn
20170606183005668 DMM <0002> subscr_conn.c:169
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_ACCEPTED}: state_chg
to SUBSCR_CONN_S_RELEASED
20170606183005668 DMM <0002> subscr_conn.c:255
Subscr_Conn(901700000014922)[0xcd22f0]{SUBSCR_CONN_S_RELEASED}: Terminating
(cause = OSMO_FSM_TERM_REGULAR)
Indeed nothing left to do, connection is discarded, phone is subscribed and
waiting for any events that would create a new connection.
So everything looks good from these logs. Cannot tell why this procedure would
repeat over and over? Does it?
~N
--
- Neels Hofmeyr <nhofmeyr(a)sysmocom.de> http://www.sysmocom.de/
=======================================================================
* sysmocom - systems for mobile communications GmbH
* Alt-Moabit 93
* 10559 Berlin, Germany
* Sitz / Registered office: Berlin, HRB 134158 B
* Geschäftsführer / Managing Directors: Harald Welte
3:49 p.m.
On 6. Jun 2017, at 19:25, Neels Hofmeyr
<nhofmeyr(a)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
7 Jun
7 Jun
4:48 a.m.
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(a)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(a)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(a)freyther.de>de>:
On 6. Jun 2017, at 19:25, Neels Hofmeyr
<nhofmeyr(a)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
4:54 a.m.
On 7. Jun 2017, at 10:48, 雪碧 0xroot
<renxianyuanqi(a)gmail.com> wrote:
Thanks for the quick reply.
I wondered if I need to clarify but then assumed it would be obvious enough. With trace I
meant packet trace to capture what is being sent between the different components.
Is a TMSI assigned? What is the TMSI?
just fond TMSI at osmo-hnbw's terminal:(0x0 not looks good )
<0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922, tmsi 0x0
5:54 a.m.
Thank you Holger and Neels.
The problem is solved now. We re-checked out the latest version and right
branch of OpenBSC. The previous branch may be wrong. Now the cellphone was
successfully attached.
Lin
2017-06-07 10:54 GMT+08:00 Holger Freyther <holger(a)freyther.de>de>:
tmsi
0x0
the phone ME might not have a TMSI initially. Not bad.
On 7. Jun 2017, at 10:48, 雪碧 0xroot
<renxianyuanqi(a)gmail.com> wrote:
Thanks for the quick reply.
I wondered if I need to clarify but then assumed it would be obvious
enough. With trace I meant packet trace to capture what is being sent
between the different components.
Is a TMSI assigned? What is the TMSI?
just fond TMSI at osmo-hnbw's terminal:(0x0 not looks good )
<0001> hnbgw.c:176 created UE context: id 0x17, imsi 901700000014922,
2538
days inactive
2539
days old
5 comments
4 participants
participants (4)
-
Holger Freyther -
Lin HUANG -
Neels Hofmeyr -
雪碧 0xroot