[cisco-voip] SRST 9.1 and 6961 with latest firmware

Anthony Kouloglou akoul at dataways.gr
Thu Jan 2 11:12:43 EST 2014


Here it is Brian,
i hope it helps. But this time the fallback occured at 1 minute!
Also the time stamp on the console logs is not correct although the 
phone does have correct time.
Here is what time wan outage occured and the time it was registered to 
the srst.

*Jan  2 09:58:00.425: %LINEPROTO-5-UPDOWN: Line protocol on Interface 
FastEthernet4, changed state to down
100.MexicoVGW#
*Jan  2 09:59:00.965: %IPPHONE-6-REGISTER_NEW: ephone-1:SEPF029295A9946 
IP:10.0.0.36 Socket:1 DeviceType:Phone has registered.

BR
Anthony

Στις 2/1/2014 5:56 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
> Try VxWorks login as "admin" with no password.
>
> *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
> *Sent:* Thursday, January 02, 2014 10:54 AM
> *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
> *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
> Hi Brian,
> whatever i put there, i cannot log in using username default and 
> password user:
>
> 100.MexicoVGW#ssh -l cisco 10.0.0.36
> Password:
>
> *******************************************************************
> ** **
> ** VOIP IPP firmware         SCCP 9.4.1.3                        **
> ** **
> **      compiled on     Nov  5 2013 at 14:54:07           **
> ** **
> ** **
> *******************************************************************
>
>
>
> VxWorks login:
> Password:
> Login incorrect
>
> *ΜΦΧ/Kind Regards*
>
> *Αντώνης Κούλογλου - Anthony Kouloglou*
>
> */Field Network Engineer, Cisco UC Specialized/*
>
>
> *DATAWAYS Communications S.A.* <http://www.dataways.gr/>
> 75, Kanari Str., GR-544 53 Thessaloniki - Greece
> Phone +30 2310 953953Fax +30 2310 953963
>
> Στις 2/1/2014 5:35 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
>     Anthony,
>
>     Those console logs are very strange.  Almost nothing in them.
>
>     Try configuring SSH on the phone and run the following debug
>     commands once logged in:
>
>     spy tstn 1
>
>     spy psccp 1
>
>     debug set provision 1
>
>     That should hopefully give more information about what’s going on.
>
>     Brian
>
>     *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
>     *Sent:* Thursday, January 02, 2014 10:27 AM
>     *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
>     <mailto:cisco-voip at puck-nether.net>
>     *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
>     Here are the console logs,
>     i realy can't see anything.
>     Can you?
>     wan outage at 08:54
>     srst registration at 08:57
>
>     BR
>     Anthony
>
>     Στις 2/1/2014 5:22 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
>         Anthony,
>
>         It’s possible the DNS timeout is causing additional delay.
>         Console log should show that though.
>
>         Thanks,
>
>         Brian Meade
>
>         *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
>         *Sent:* Thursday, January 02, 2014 10:21 AM
>         *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
>         <mailto:cisco-voip at puck-nether.net>
>         *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest firmware
>
>         Brian,
>         i cannot see anything suspicious at the log.
>         I am using dns name for ccms and it is sure that when the wan
>         is out, dns is not accessible.
>         Could this be the reason?
>
>         BR
>         Anthony
>
>         Στις 2/1/2014 5:13 μμ, ο/η Brian Meade (brmeade) έγραψε:
>
>             Anthony,
>
>             Take a look at the console logs to see if anything is
>             causing a delay.
>
>             The SRST option will never display any sort of status
>             indication as the phone doesn’t maintain a backup
>             registration with the SRST router.  It just fails over to
>             that option if all the CM’s are down.
>
>             Brian
>
>             *From:*Anthony Kouloglou [mailto:akoul at dataways.gr]
>             *Sent:* Thursday, January 02, 2014 10:05 AM
>             *To:* Brian Meade (brmeade); cisco-voip at puck-nether.net
>             <mailto:cisco-voip at puck-nether.net>
>             *Subject:* Re: [cisco-voip] SRST 9.1 and 6961 with latest
>             firmware
>
>             Well,
>             i have upgraded to 9.4.1.3 and it worked!
>             But i have to wait almost 2 and a half minutes! I thought
>             with the default settings for keepelives, in 90 seconds it
>             should register!
>             I have never waited more than 2 minutes...
>             Sorry for that :-[
>             At the web page though, the 3rd option (srst) displays
>             only the IP of the srst with no indication if it is ok or not.
>
>             BR
>             Anthony
>
>             Στις 2/1/2014 3:32 μμ, ο/η Anthony Kouloglou έγραψε:
>
>                 Hi Brian,
>                 i have dowloaded the xml file for the 9.1.1sr1 phoneload.
>                 There it is clearly stated the name of the SRST and
>                 it's IP address.
>                 The srst does not show on the phone's web page but it
>                 gets registered to it when there is a WAN outage.
>                 I will upgrade and see the xml file and the
>                 packet/console logs for 9.4.1.
>                 Just one last question: must the srst be shown as srst
>                 in parenthesis () when everything is ok?
>                 for example, primary and secondary ccms are always
>                 shown as (active) and (standby).
>
>                 BR
>                 Anthony
>
>                 Anthony,
>
>                     The phone console logs and a packet capture on the
>                     phone side will probably help with determining why
>                     the phone isn’t registering with the SRST router.
>
>                     On the old firmware, there was a bug where the
>                     SRST address didn’t properly show up.  Having
>                     trouble finding it though.
>
>                     Brian
>
>                     *From:*cisco-voip
>                     [mailto:cisco-voip-bounces at puck.nether.net] *On
>                     Behalf Of *Anthony Kouloglou
>                     *Sent:* Wednesday, January 01, 2014 11:26 AM
>                     *To:* cisco-voip at puck-nether.net
>                     <mailto:cisco-voip at puck-nether.net>
>                     *Subject:* [cisco-voip] SRST 9.1 and 6961 with
>                     latest firmware
>
>                     Hi all,
>                     i wish you a happy new year!
>                     I have an 6961, running the latest 9.4.1 firmware
>                     which registers on CUCM 9.1.
>                     It is at a remote site which has an 881v where
>                     call-manager-fallback is configured (SRST 9.1)
>                     Although it gets the srst as a third option after
>                     the Publisher and subscriber, when the wan
>                     connection to the main site is off, it does not
>                     even try to get registered! (i have debugged
>                     ephone registration)
>                     I have downgraded to 9.3 and 9.2 and still nothing.
>                     Finally, when i downgraded to 9.1.1sr1 it started
>                     to get register to the SRST.
>                     Funny thing is that web page of the phone does not
>                     report the srst after the 2 ccms!
>                     Any ideas would be appreciated!
>
>                     BR
>                     Anthony
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20140102/3ab41b8b/attachment.html>
-------------- next part --------------
provision_activate :
provision_signal_activate_ready :
provision_check_config_restart :
00:01:10:49.538 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:10:49.540 - I/TCP    : socket= 17: recv ERROR= 60:errno = 0x3c
00:01:10:49.540 - I/TCP    : socket= 17: STATUS: Connection to CM disconnected
00:01:10:49.540 - I/sapp_sapp_last_unreg_reason_set(): sapp_get_info(1) for last_unreg_reason_set
00:01:10:49.540 - I/sapp_sapp_last_unreg_reason_set(): ori_reason(25), set_reason(10), dest_ip(0x00000000), local_port(0)
00:01:10:49.542 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:10:49.544 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:49.544 - I/
00:01:10:49.544 - I/SCCPCM  25   : [S_REGISTERED] [E_TCP_EVENTS] [S_REGISTERED]
00:01:10:49.544 - I/SCCPCM  1 :25: sem_tcp_events      : event= 3
00:01:10:49.546 - I/SCCP    1    : push_event          : SCCPCM  <- E_ERROR.
00:01:10:49.546 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:49.546 - I/
00:01:10:49.546 - I/SCCPCM  25   : [S_REGISTERED] [E_ERROR] [S_WF_UNREG_RES]
00:01:10:49.548 - I/SCCPCM  1 :25: sem_registered_error: XXCM[0] 213.140.133.68:2000: error= ERROR_TCP_CLOSE
00:01:10:49.548 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_UNREG_REQ.
00:01:10:49.550 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_UNREGISTER_ACK.
00:01:10:49.550 - I/SCCP    1    : push_event          : SCCPCM  <- E_UNREG_ACK.
00:01:10:49.552 - I/SCCP    1    : push_event          : SCCPCM  <- E_DISCON_REQ.
00:01:10:49.552 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:10:49.552 - I/sapp_sccp_main2()- sapp_sccp_nready(4)
00:01:10:49.554 - I/
00:01:10:49.554 - I/SCCPREG 1    : [S_REGISTERED] [SCCPREG_E_UNREG_REQ] [S_UNREGISTERING]
00:01:10:49.554 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:10:49.556 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:16876
00:01:10:49.556 - I/platform_send: sock(17), buf(0x94d24890), len(16)
00:01:10:49.556 - I/SAPP   : sapp_socket_send         : socket= 17: ERROR: 32:errno = 0x20
00:01:10:49.556 - I/SCCPMSG      : send_message        : [17] ERROR= 32
00:01:10:49.558 - I/SCCP    1    : push_event          : SCCPCM  <- E_UNREG_ACK.
00:01:10:49.558 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_CLEANUP.
00:01:10:49.560 - I/sapp_sccp_main2()- sapp_sccp_nready(5)
00:01:10:49.560 - I/
00:01:10:49.560 - I/SCCPREG 1    : [S_UNREGISTERING] [SCCPREG_E_UNREGISTER_ACK] [S_UNREGISTERING]
00:01:10:49.562 - I/SCCP    1    : push_event          : SCCPCM  <- E_UNREG_ACK.
00:01:10:49.562 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_CLEANUP.
00:01:10:49.564 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:10:49.564 - I/
00:01:10:49.564 - I/SCCPCM  25   : [S_WF_UNREG_RES] [E_UNREG_ACK] [S_CONNECTED]
00:01:10:49.564 - I/SAPP   : sapp_sessionstatus       : status= 3: cm_idx= 0
00:01:10:49.572 - I/Disconnected from CM
00:01:10:49.572 - I/
00:01:10:49.572 - I/------------=={ MENU }==------------
00:01:10:49.572 - I/tstone state = CLOSED
00:01:10:49.572 - I/cmaddr = [213:140:133:68:2000]
00:01:10:49.574 - I/call_state = 
00:01:10:49.574 - I/active line/call_id =    0/   0
00:01:10:49.574 - I/ts_ln  ts_callid  sccp_ln  sccp_callref  ridle  rport  c_state  m_state
00:01:10:49.574 - I/
00:01:10:49.574 - I/SAPP   : sapp_sapp_sessionstatus_cm_connected: reg_stat FAIL to ACCU
00:01:10:49.576 - I/SAPP   : sapp_sapp_sessionstatus_cm_connected: CM[213.140.133.68]:2000
00:01:10:49.576 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:10:49.576 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:2 ts_idx:0 cm_idx:0 doing_defer:0
00:01:10:49.576 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:2 ts_idx:1 cm_idx:1 doing_defer:0
00:01:10:49.578 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:10:49.578 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:10:49.578 - I/
00:01:10:49.580 - I/SCCPCM  25   : [S_CONNECTED] [E_DISCON_REQ] [S_IDLE]
00:01:10:49.580 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:10:49.580 - I/PLAT   : platform_shutdown        : socket= 17: ERROR= 22:errno = 0x16
00:01:10:49.582 - I/SAPP   : sapp_socket_close        : socket= 17->0
00:01:10:49.582 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:10:49.582 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:10:49.582 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:10:49.582 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:10:49.584 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:2 ts_idx:1 cm_idx:1 doing_defer:0
00:01:10:49.584 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:10:49.584 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:10:49.586 - I/
00:01:10:49.586 - I/SCCPREC 1    : [S_IDLE] [E_DEV_NOTIFY] [S_PRI_CHECK]
00:01:10:49.586 - I/SCCPREC 1 :1 : stop_timer          : 0x94dbe6dc
00:01:10:49.586 - I/SAPP   : 0:0: sapp_sapp_all_streams_idle
00:01:10:49.586 - I/SAPP   : 0-0: sapp_sapp_all_streams_idle: count= 0
00:01:10:49.588 - I/SAPP   : 0:0: sapputil_cb_is_there_no_call_left
00:01:10:49.588 - I/SCCP    1    : push_event          : SCCPREC <- E_FIND_PRI.
00:01:10:49.590 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:10:49.590 - I/SCCPCM  25   : not handled: [S_IDLE] [E_UNREG_ACK]
00:01:10:49.590 - I/sapp_sccp_main2()- sapp_sccp_nready(5)
00:01:10:49.590 - I/
00:01:10:49.592 - I/SCCPREG 1    : [S_UNREGISTERING] [SCCPREG_E_CLEANUP] [S_IDLE]
00:01:10:49.592 - I/sapp_sccp_main2()- sapp_sccp_nready(4)
00:01:10:49.592 - I/SCCPCM  25   : not handled: [S_IDLE] [E_UNREG_ACK]
00:01:10:49.594 - I/sapp_sccp_main2()- sapp_sccp_nready(3)
00:01:10:49.594 - I/
00:01:10:49.594 - I/SCCPREG 1    : [S_IDLE] [SCCPREG_E_CLEANUP] [S_IDLE]
00:01:10:49.594 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:10:49.594 - I/SCCPREC 1    : not handled: [S_PRI_CHECK] [E_DEV_NOTIFY]
00:01:10:49.596 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:10:49.596 - I/SCCPREC 1    : not handled: [S_PRI_CHECK] [E_DEV_NOTIFY]
00:01:10:49.596 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:49.596 - I/
00:01:10:49.598 - I/SCCPREC 1    : [S_PRI_CHECK] [E_FIND_PRI] [S_FIND_PRI]
00:01:10:49.598 - I/SCCPREC 1 :1 : sem_pri_check_find_pri: XXCM[1] 213.140.133.69:2000: trying to register
00:01:10:49.598 - I/SCCPREC 1 :1 : Changing keepalive timeout 2 from 60000ms to: 10000ms
00:01:10:49.600 - I/SCCP    1    : push_event          : SCCPCM  <- E_REG_REQ.
00:01:10:49.600 - I/SCCPREC 1 :1 : start_timer         : T_WF_REGISTER: 0x94dbe6dc: 93000ms
00:01:10:49.600 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:49.602 - I/
00:01:10:49.602 - I/SCCPCM  26   : [S_CONNECTED] [E_REG_REQ] [S_WF_REG_RES]
00:01:10:49.602 - I/SCCPCM  1 :26: stop_timer          : 0x94dbe604
00:01:10:49.602 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_REG_REQ.
00:01:10:49.602 - I/SCCPCM  1 :26: start_timer         : T_WF_REG_RES: 0x94dbe604: 90000ms
00:01:10:49.604 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:49.604 - I/
00:01:10:49.604 - I/SCCPREG 1    : [S_IDLE] [SCCPREG_E_REG_REQ] [S_REGISTERING]
00:01:10:49.606 - I/SAPP   : 0:0: sapputil_cb_get_device_unreg_alarm
00:01:10:49.608 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:18
00:01:10:49.608 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:10:49.610 - I/SAPP   : sapp_socket_send         : socket= 18: addr=0x0a000024:35024
00:01:10:49.610 - I/platform_send: sock(18), buf(0x94dbb1d0), len(1219)
00:01:10:49.612 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:18
00:01:10:49.612 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:10:49.614 - I/SAPP   : sapp_socket_send         : socket= 18: addr=0x0a000024:35024
00:01:10:49.614 - I/platform_send: sock(18), buf(0x94d93790), len(136)
00:01:10:49.616 - I/sapp_sapp_last_unreg_reason_set(): ori_reason(10), set_reason(25), dest_ip(0x00000000), local_port(0)
00:01:10:49.616 - E/ACCU:       SCCP REG OK[(-1,0), (1,0)]
00:01:10:49.620 - E/ACCU:  SCCP REG FAIL
00:01:10:56.662 - I/SCCPCM  1 :26: timeout_callback    : T_WF_KA_ACK: 0x94dbe5e0
00:01:10:56.662 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:10:56.664 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:56.664 - I/
00:01:10:56.664 - I/SCCPCM  26   : [S_WF_REG_RES] [E_TIMEOUT] [S_WF_REG_RES]
00:01:10:56.664 - I/SCCPCM  1 :26: sem_connected_timeout: XXCM[1] 213.140.133.69:2000: retry= 1
00:01:10:56.664 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:18
00:01:10:56.666 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:10:56.666 - I/SAPP   : sapp_socket_send         : socket= 18: addr=0x0a000024:35024
00:01:10:56.666 - I/platform_send: sock(18), buf(0x94d248b8), len(12)
00:01:10:56.668 - I/SCCPCM  1 :26: start_timer         : T_WF_KA_ACK: 0x94dbe5e0: 10000ms
00:01:10:56.670 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:10:56.670 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:10:56.672 - I/
00:01:10:56.672 - I/SCCPCM  26   : [S_WF_REG_RES] [E_KEEPALIVE_ACK] [S_WF_REG_RES]
00:01:10:56.672 - I/SCCPREC 1 :1 : Changing keepalive timeout 2 from 10000ms to: 30000ms

      rwxrwxrwx 0:0 a: -1 i:0 Jan  2, 2014  9:59:34am    2230 local

      rwxrwxrwx 0:0 a: -1 i:0 Jan  2, 2014  9:59:36am    6690 config

Copying files to flash... Complete.
..00:01:11:06.670 - I/SCCPCM  1 :26: timeout_callback    : T_WF_KA_ACK: 0x94dbe5e0
00:01:11:06.670 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:06.672 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:06.672 - I/
00:01:11:06.672 - I/SCCPCM  26   : [S_WF_REG_RES] [E_TIMEOUT] [S_WF_REG_RES]
00:01:11:06.672 - I/SCCPCM  1 :26: sem_connected_timeout: XXCM[1] 213.140.133.69:2000: retry= 1
00:01:11:06.674 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:18
00:01:11:06.674 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:06.676 - I/SAPP   : sapp_socket_send         : socket= 18: addr=0x0a000024:35024
00:01:11:06.676 - I/platform_send: sock(18), buf(0x94d24700), len(12)
00:01:11:06.676 - I/SCCPCM  1 :26: start_timer         : T_WF_KA_ACK: 0x94dbe5e0: 30000ms
00:01:11:06.678 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:11:06.678 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:06.680 - I/
00:01:11:06.680 - I/SCCPCM  26   : [S_WF_REG_RES] [E_KEEPALIVE_ACK] [S_WF_REG_RES]

*Jan  2 09:59:00.961: %IPPHONE-6-REG_ALARM: 12: Name=SEPF029295A9946 Load=SCCP69xx.9-4-1-3 Last=CM-reset-TCP
*Jan  2 09:59:00.965: %IPPHONE-6-REGISTER_NEW: ephone-1:SEPF029295A9946 IP:10.0.0.36 Socket:1 DeviceType:Phone has registered.provision_activate :
provision_signal_activate_ready :
provision_check_config_restart :
00:01:11:07.738 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:11:07.740 - I/TCP    : socket= 18: recv ERROR= 60:errno = 0x3c
00:01:11:07.740 - I/TCP    : socket= 18: STATUS: Connection to CM disconnected
00:01:11:07.740 - I/sapp_sapp_last_unreg_reason_set(): sapp_get_info(1) for last_unreg_reason_set
00:01:11:07.740 - I/sapp_sapp_last_unreg_reason_set(): ori_reason(25), set_reason(10), dest_ip(0x00000000), local_port(0)
00:01:11:07.742 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:07.742 - I/TCP    : no sockets
00:01:11:07.744 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.744 - I/
00:01:11:07.744 - I/SCCPCM  26   : [S_WF_REG_RES] [E_TCP_EVENTS] [S_WF_REG_RES]
00:01:11:07.744 - I/SCCPCM  1 :26: sem_tcp_events      : event= 3
00:01:11:07.746 - I/SCCP    1    : push_event          : SCCPCM  <- E_ERROR.
00:01:11:07.746 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.provision_activate74 :
6 - I/
provision_activate00:01:11:07. :
748 - I/SCCPCM  2provision_signal_activate_ready6   : [S_ :
WF_REG_RES] [E_ERprovision_check_config_restartROR] [S_ID :
LE]
provision_signal_activate_ready00 :
:01:11:07.748 - Iprovision_check_config_restart/SCCPCM  1 :
 :26: sccpcm_sem_wf_reg_res_error: XXCM[1] 213.140.133.69:2000: error= ERROR_TCP_CLOSE
xml_config00:01:11:07.748 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:18
_keymap00:01:11:07.748 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
(00:01:11:07.750 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
100:01:11:07.750 - I/SAPP   : sapp_socket_close        : socket= 18->0
65200:01:11:07.750 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
): ----- 
00:01:11:07.752 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
 deck: 00:01:11:07.752 - I/Disconnected from CM
sCMEtemplat00:01:11:07.752 - I/
e00:01:11:07.752 - I/------------=={ MENU }==------------

00:01:11:07.752 - I/tstone state = CLOSED
 card: 00:01:11:07.752 - I/call_state = 
template00:01:11:07.754 - I/active line/call_id =    0/   0

00:01:11:07.754 - I/ts_ln  ts_callid  sccp_ln  sccp_callref  ridle  rport  c_state  m_state
 hre00:01:11:07.754 - I/
f: 00:01:11:07.754 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: reg_stat FAIL to ACCU
#sCMEtemplat00:01:11:07.754 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
e?template00:01:11:07.756 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0

00:01:11:07.756 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
xml_config_keyma00:01:11:07.756 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
p00:01:11:07.758 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
(00:01:11:07.758 - I/
165700:01:11:07.758 - I/SCCPREC 1    : [S_FIND_PRI] [E_DEV_NOTIFY] [S_FIND_PRI]
): ----- 
00:01:11:07.760 - I/SCCPREC 1 :1 : stop_timer          : 0x94dbe6dc
00:01:11:07.760 - I/SCCPREC 1 :1 : sem_find_pri_dev_notify: XXCM[1] 213.140.133.69:2000: connect or register failed, trying to find next
00:01:11:07.760 - I/SCCPREC 1 :1 : sem_find_pri_timeout: XXCM[2] 10.0.0.33:2000: trying to connect
00:01:11:07.762 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:07.762 - I/SCCPREC 1 :1 : start_timer         : T_WF_CONNECT: 0x94dbe6dc: 185000ms
00:01:11:07.762 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.762 - I/
00:01:11:07.764 - I/SCCPCM  28   : [S_IDLE] [E_CON_REQ] [S_WF_DNS_QUERY]
00:01:11:07.764 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:07.764 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.764 - I/
00:01:11:07.766 - I/SCCPCM  28   : [S_WF_DNS_QUERY] [E_CON_REQ] [S_WF_CON_RES]
00:01:11:07.766 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 2
00:01:11:07.766 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[10.0.0.33]2000: down, state= 0
00:01:11:07.766 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:07.766 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:07.768 - I/----SCCP--cmcb #2 of type 3 using ip_addr of type 0 to connect
00:01:11:07.768 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 2
00:01:11:07.770 - I/g_cmlist_accu[2]: host_prefer(10.0.0.33)
00:01:11:07.770 - I/addr_type:         1
00:01:11:07.770 - I/tmp:               addr_prefer(10.0.0.33), fqdn_prefer()
00:01:11:07.770 - I/cminfo->cmaddr:    addr_prefer(10.0.0.33), fqdn_prefer()
00:01:11:07.772 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[10.0.0.33]:2000: opening, ts_idx(2), cm_idx(2), doing_defer(0)
00:01:11:07.772 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:07.772 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:07.772 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:1 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:07.774 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= -1:-1
00:01:11:07.774 - I/PLAT   : platform_socket_v4       : sock(17), bind port(35025) ok!
00:01:11:07.774 - I/PLAT   : platform_socket_v4       : sock(17), bind port(35025), tos(96)
00:01:11:07.776 - I/SAPP   : sapp_socket_open         : socket= 17:17, addr_type=0. sec_mode=1. local_port=35025
00:01:11:07.776 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.776 - I/SAPP   : sapp_socket_connect_v6   : socket= 17: addr=[10.0.0.33]:2000. local_port=35025
00:01:11:07.776 - I/platform_connect_v4: addr/port=[10.0.0.33]:2000.
00:01:11:07.778 - I/PLAT   : connect                  : socket= 17: ERROR= 68:errno = 0x44
00:01:11:07.778 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 17
00:01:11:07.778 - I/SCCPCM  1 :28: start_timer         : T_WF_CON_RES: 0x94dbe550: 180000ms
00:01:11:07.782 - E/ACCU:       SCCP REG OK[(-1,0), (-1,0)]
00:01:11:07.784 - E/ACCU:  SCCP REG FAIL
00:01:11:07.786 - I/TCP    : socket= 17: connected: addr=0x0a000024:35025
00:01:11:07.786 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:07.788 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.788 - I/
00:01:11:07.788 - I/SCCPCM  28   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:11:07.790 - I/SCCPCM  1 :28: sem_tcp_events      : event= 2
00:01:11:07.790 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_ACK.
00:01:11:07.792 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.792 - I/
00:01:11:07.792 - I/SCCPCM  28   : [S_WF_CON_RES] [E_CON_ACK] [S_CONNECTED]
00:01:11:07.792 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:11:07.792 - I/SCCPCM  1 :28: sem_wf_con_res_con_ack: XXCM[2] 10.0.0.33:2000: connected
00:01:11:07.794 - I/SAPP   : sapp_sessionstatus       : status= 3: cm_idx= 2
00:01:11:07.794 - I/SAPP   : sapp_sapp_sessionstatus_cm_connected: CM[10.0.0.33]:2000
00:01:11:07.794 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:07.794 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:07.794 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:07.796 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:2 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:07.796 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:11:07.798 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.798 - I/
00:01:11:07.798 - I/SCCPREC 1    : [S_FIND_PRI] [E_DEV_NOTIFY] [S_FIND_PRI]
00:01:11:07.798 - I/SCCPREC 1 :1 : sem_find_pri_dev_notify: XXCM[2] 10.0.0.33:2000: connected
00:01:11:07.798 - I/SCCPREC 1 :1 : sem_find_pri_dev_notify: XXCM[2] 10.0.0.33:2000: trying to register
00:01:11:07.800 - I/SCCPREC 1 :1 : Changing keepalive timeout 2 from 30000ms to: 10000ms
00:01:11:07.800 - I/SCCP    1    : push_event          : SCCPCM  <- E_REG_REQ.
00:01:11:07.800 - I/SCCPREC 1 :1 : start_timer         : T_WF_REGISTER: 0x94dbe6dc: 93000ms
00:01:11:07.802 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.802 - I/
00:01:11:07.802 - I/SCCPCM  28   : [S_CONNECTED] [E_REG_REQ] [S_WF_REG_RES]
00:01:11:07.802 - I/SCCPCM  1 :28: stop_timer          : 0x94dbe574
00:01:11:07.804 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_REG_REQ.
00:01:11:07.804 - I/SCCPCM  1 :28: start_timer         : T_WF_REG_RES: 0x94dbe574: 90000ms
00:01:11:07.804 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.806 - I/
00:01:11:07.806 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_REG_REQ] [S_REGISTERING]
00:01:11:07.806 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:07.806 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:18
00:01:11:07.806 - I/SAPP   : sapp_get_socket2_by_id    i=2: id= -1:18
00:01:11:07.808 - I/SAPP   : sapp_get_socket2_by_id provision_activate   :
 i=3: id= -1:18
provision_activate00: :
01:11:07.808 - I/provision_signal_activate_readySAPP   :  :
sapp_get_socket2_provision_check_config_restartby_id    i :
=4: id= -1:18
provision_signal_activate_ready00:01:11:07. :
808 - I/SAPP   : provision_check_config_restartsapp_get_s :
ocket2_by_id    i=5: id= -1:18
00:01:11:07.808 - I/SAPP   : sapp_get_socket2_by_id    i=6: id= -1:18
00:01:11:07.808 - I/SAPP   : sapp_get_socket2_by_id    i=7: id= -1:18
00:01:11:07.810 - I/SAPP   : sapp_get_socket2_by_id    i=8: id= -1:18
00:01:11:07.810 - I/SAPP   : sapp_get_socket2_by_id    i=9: id= -1:18
00:01:11:07.810 - I/SAPP   : sapp_get_socket2_by_id    i=10: id= -1:18
00:01:11:07.810 - I/SCCPMSG      : send_message        : [18] ERROR= -1
00:01:11:07.812 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_CLEANUP.
00:01:11:07.812 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_REG_REQ.
00:01:11:07.812 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:07.814 - I/
00:01:11:07.814 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_CLEANUP] [S_IDLE]
00:01:11:07.814 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.814 - I/
00:01:11:07.816 - I/SCCPREG 1    : [S_IDLE] [SCCPREG_E_REG_REQ] [S_REGISTERING]
00:01:11:07.816 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.818 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.818 - I/platform_send: sock(17), buf(0x94d40810), len(104)
00:01:11:07.820 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.822 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.822 - I/platform_send: sock(17), buf(0x94d93790), len(136)
00:01:11:07.824 - I/sapp_sapp_last_unreg_reason_set(): ori_reason(10), set_reason(25), dest_ip(0x00000000), local_port(0)
00:01:11:07.826 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:07.828 - I/
00:01:11:07.828 - I/SCCP    1    : push_tcp            : recv[17] <- REGISTER_ACK[0x81] 24:0:44
00:01:11:07.828 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_REGISTER_ACK.
00:01:11:07.830 - I/Message id 9b is not parsed!
00:01:11:07.830 - I/
00:01:11:07.830 - I/SCCP    1    : push_tcp            : recv[17] <- CAPABILITIES_REQ[0x9b] 4:0:44
00:01:11:07.832 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_CAPABILITIES_REQ.
00:01:11:07.832 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:07.834 - I/
00:01:11:07.834 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_REGISTER_ACK] [S_REGISTERING]
00:01:11:07.834 - I/SAPP   : 0:0: sapp_register_ack        
00:01:11:07.834 - I/sapp_sapp_register_ack(): PSCCP_EVT_REGACK
00:01:11:07.840 - I/SCCP    1    : push_event          : SCCPCM  <- E_REG_ACK.
00:01:11:07.842 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.842 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.842 - I/platform_send: sock(17), buf(0x94d24890), len(16)
00:01:11:07.844 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.846 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.846 - I/platform_send: sock(17), buf(0x94d24890), len(20)
00:01:11:07.848 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.848 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.850 - I/platform_send: sock(17), buf(0x94d24890), len(20)
00:01:11:07.852 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.852 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.852 - I/platform_send: sock(17), buf(0x94d24890), len(20)
00:01:11:07.854 - I/SCCPMSG      : send_message        : [17]          -> BUTTON_TEMPLATE_REQ       (msgid:14)
00:01:11:07.854 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.856 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.856 - I/platform_send: sock(17), buf(0x94d24890), len(16)
00:01:11:07.858 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:07.858 - I/
00:01:11:07.858 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_CAPABILITIES_REQ] [S_REGISTERING]
00:01:11:07.860 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.862 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.862 - I/platform_send: sock(17), buf(0x94d93790), len(304)
00:01:11:07.864 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.864 - I/
00:01:11:07.864 - I/SCCPCM  28   : [S_WF_REG_RES] [E_REG_ACK] [S_REGISTERED]
00:01:11:07.864 - I/SCCPCM  1 :28: stop_timer          : 0x94dbe574
00:01:11:07.864 - I/SCCPCM  1 :28: sem_wf_reg_res_reg_ack: XXCM[2] 10.0.0.33:2000: registered
00:01:11:07.866 - I/SCCPREC 1 :1 : Changing keepalive timeout 1 from 30000ms to: 30000ms
00:01:11:07.866 - I/SCCPREC 1 :1 : Changing keepalive timeout 2 from 10000ms to: 60000ms
00:01:11:07.866 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 6000ms
00:01:11:07.866 - I/SAPP   : sapp_sessionstatus       : status= 4: cm_idx= 2
00:01:11:07.866 - I/SAPP   : sapp_sapp_sessionstatus_cm_registered: CM[10.0.0.33]:2000
00:01:11:07.868 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:07.868 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:07.868 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:3 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:07.872 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(24), PSCCP_EVT_REGACK...
00:01:11:07.872 - I/TSTN> 'tstone_proc_msg_psccp_info()'. final JaDTP(2), ucm proto_ver(0x013ce011)
00:01:11:07.974 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:07.974 - I/Message id 12 is not parsed!
00:01:11:07.974 - I/
00:01:11:07.974 - I/SCCP    1    : push_tcp            : recv[17] <- SERVER_REQ[0x12] 4:0:12
00:01:11:07.976 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:07.978 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.978 - I/
00:01:11:07.978 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:07.980 - I/SCCPMSG      : send_message        : [17]          -> SERVER_RES                (msgid:158)
00:01:11:07.980 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.982 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.982 - I/platform_send: sock(17), buf(0x94d93790), len(372)
00:01:11:07.984 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:07.986 - I/
00:01:11:07.986 - I/SCCP    1    : push_tcp            : recv[17] <- BUTTON_TEMPLATE_REQ[0xe] 8:0:16
00:01:11:07.986 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:07.988 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.988 - I/
00:01:11:07.988 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:07.990 - I/SCCPMSG      : send_message        : [17]          -> BUTTON_TEMPLATE           (msgid:151)
00:01:11:07.990 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:07.992 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:07.992 - I/platform_send: sock(17), buf(0x94d40810), len(108)
00:01:11:07.996 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:07.996 - I/
00:01:11:07.996 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
00:01:11:07.996 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:07.998 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:07.998 - I/
00:01:11:07.998 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.000 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
00:01:11:08.000 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.002 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.002 - I/platform_send: sock(17), buf(0x94d93790), len(29)

00:01:11:08.038 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
 00:01:11:08.040 - I/
 00:01:11:08.040 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
 00:01:11:08.042 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
 00:01:11:08.042 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 00:01:11:08.044 - I/
00:01:11:08.044 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 00:01:11:08.044 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
r00:01:11:08.044 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
w00:01:11:08.046 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
x00:01:11:08.046 - I/platform_send: sock(17), buf(0x94d93790), len(23)
r00:01:11:08.050 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
w00:01:11:08.050 - I/
x00:01:11:08.052 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
r00:01:11:08.052 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
w00:01:11:08.052 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
x00:01:11:08.054 - I/
 00:01:11:08.054 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
000:01:11:08.054 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
:00:01:11:08.054 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
000:01:11:08.056 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
 00:01:11:08.056 - I/platform_send: sock(17), buf(0x94d93790), len(23)
a00:01:11:08.060 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
:00:01:11:08.060 - I/
 00:01:11:08.062 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
-00:01:11:08.062 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
100:01:11:08.062 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 i:00:01:11:08.064 - I/
000:01:11:08.064 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 00:01:11:08.064 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
Jan00:01:11:08.064 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
 00:01:11:08.066 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
 00:01:11:08.066 - I/platform_send: sock(17), buf(0x94d93790), len(23)
200:01:11:08.070 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
, 00:01:11:08.070 - I/
201400:01:11:08.072 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
 00:01:11:08.072 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
 00:01:11:08.072 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
900:01:11:08.074 - I/
:00:01:11:08.074 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
500:01:11:08.074 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
900:01:11:08.074 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
:00:01:11:08.076 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
1400:01:11:08.076 - I/platform_send: sock(17), buf(0x94d93790), len(23)
a00:01:11:08.080 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
m00:01:11:08.080 - I/
 00:01:11:08.082 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
   00:01:11:08.082 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
223300:01:11:08.084 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 00:01:11:08.084 - I/
l00:01:11:08.084 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
o00:01:11:08.084 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
c00:01:11:08.086 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
a00:01:11:08.086 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
l00:01:11:08.086 - I/platform_send: sock(17), buf(0x94d93790), len(23)
00:01:11:08.090 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)

00:01:11:08.092 - I/

00:01:11:08.092 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
 00:01:11:08.092 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
 00:01:11:08.094 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 00:01:11:08.094 - I/
 00:01:11:08.094 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 00:01:11:08.094 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
 00:01:11:08.096 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
r00:01:11:08.096 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
w00:01:11:08.096 - I/platform_send: sock(17), buf(0x94d93790), len(23)
x00:01:11:08.104 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
r00:01:11:08.104 - I/
w00:01:11:08.104 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
x00:01:11:08.106 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
r00:01:11:08.106 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
w00:01:11:08.106 - I/
x00:01:11:08.108 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 00:01:11:08.108 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
000:01:11:08.108 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
:00:01:11:08.110 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
000:01:11:08.110 - I/platform_send: sock(17), buf(0x94d93790), len(23)
 00:01:11:08.114 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
a:00:01:11:08.114 - I/
 00:01:11:08.114 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
-00:01:11:08.116 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
100:01:11:08.116 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 i:00:01:11:08.116 - I/
000:01:11:08.118 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 00:01:11:08.118 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
Jan00:01:11:08.118 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
 00:01:11:08.120 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.120 - I/platform_send: sock(17), buf(0x94d93790), len(23)
 00:01:11:08.124 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
200:01:11:08.124 - I/
, 00:01:11:08.124 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
201400:01:11:08.126 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
 00:01:11:08.126 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 00:01:11:08.126 - I/
900:01:11:08.128 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
:00:01:11:08.128 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
5900:01:11:08.128 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
:00:01:11:08.130 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
2200:01:11:08.130 - I/platform_send: sock(17), buf(0x94d93790), len(23)
a00:01:11:08.134 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
m00:01:11:08.134 - I/
00:01:11:08.134 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
 00:01:11:08.136 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.136 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
 00:01:11:08.136 - I/
  00:01:11:08.138 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
669000:01:11:08.138 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
 00:01:11:08.138 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
c00:01:11:08.140 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
o00:01:11:08.140 - I/platform_send: sock(17), buf(0x94d93790), len(23)
n00:01:11:08.144 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
f00:01:11:08.144 - I/
i00:01:11:08.146 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_REQ[0xb] 8:0:16
g00:01:11:08.146 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.

00:01:11:08.146 - I/sapp_sccp_main2()- sapp_sccp_nready(0)

Copying00:01:11:08.148 - I/
 files to flash...00:01:11:08.148 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
 Complete.
00:01:11:08.148 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_V2              (msgid:327)
.00:01:11:08.148 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
.00:01:11:08.150 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.152 - I/platform_send: sock(17), buf(0x94d93790), len(23)
00:01:11:08.154 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.154 - I/
00:01:11:08.154 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.156 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.156 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.158 - I/
00:01:11:08.158 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.158 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.160 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.160 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.162 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.164 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.164 - I/
00:01:11:08.166 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.166 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.166 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.168 - I/
00:01:11:08.168 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.168 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.170 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.170 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.172 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.174 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.176 - I/
00:01:11:08.176 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.176 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.176 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.178 - I/
00:01:11:08.178 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.178 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.180 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.180 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.182 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.184 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.186 - I/
00:01:11:08.186 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.186 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.188 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.188 - I/
00:01:11:08.188 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.190 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.190 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.192 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.192 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.194 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.196 - I/
00:01:11:08.196 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.196 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.198 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.198 - I/
00:01:11:08.198 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.200 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.200 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.202 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.202 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.204 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.206 - I/
00:01:11:08.206 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_REQ[0xa] 8:0:16
00:01:11:08.206 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SRST.
00:01:11:08.208 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.208 - I/
00:01:11:08.208 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SRST] [S_REGISTERING]
00:01:11:08.210 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_V2         (msgid:329)
00:01:11:08.210 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.212 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.212 - I/platform_send: sock(17), buf(0x94d93790), len(18)
00:01:11:08.214 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.216 - I/
00:01:11:08.216 - I/SCCP    1    : push_tcp            : recv[17] <- BUTTON_TEMPLATE[0x97] 100:0:108
00:01:11:08.216 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_BUTTON_TEMPLATE_RES.
00:01:11:08.218 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.218 - I/
00:01:11:08.218 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_BUTTON_TEMPLATE_RES] [S_REGISTERING]
00:01:11:08.218 - I/SAPP   : 0:0: sapp_buttontemplate_res  
00:01:11:08.220 - I/SCCPREG 1 :1 : sccpreg_sem_button_template_res: linecnt= 12, speeddialcnt= 6, serviceeurlcnt= 0, featurecnt= 0
00:01:11:08.220 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.222 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.222 - I/platform_send: sock(17), buf(0x94d24818), len(12)
00:01:11:08.226 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.226 - I/
00:01:11:08.226 - I/SCCP    1    : push_tcp            : recv[17] <- SOFTKEY_TEMPLATE_RES[0x108] 776:0:784
00:01:11:08.228 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SOFTKEY_TEMPLATE_RES.
00:01:11:08.228 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.230 - I/
00:01:11:08.230 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SOFTKEY_TEMPLATE_RES] [S_REGISTERING]
00:01:11:08.230 - I/SAPP   : 0:0: sapp_softkeytemplate_res 
00:01:11:08.230 - I/SCCPREG 1 :1 : sccpreg_sem_softkey_template_res: softkeys= 32
00:01:11:08.232 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.232 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.232 - I/platform_send: sock(17), buf(0x94d24818), len(12)
00:01:11:08.236 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.236 - I/
00:01:11:08.238 - I/SCCP    1    : push_tcp            : recv[17] <- SOFTKEY_SET_RES[0x109] 784:0:792
00:01:11:08.238 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SOFTKEY_SET_RES.
00:01:11:08.240 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.240 - I/
00:01:11:08.240 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SOFTKEY_SET_RES] [S_REGISTERING]
00:01:11:08.242 - I/SAPP   : 0:0: sapp_softkeyset_res      
00:01:11:08.242 - I/SCCPREG 1 :1 : sccpreg_sem_softkey_set_res: softkeysets= 13
00:01:11:08.242 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.242 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.244 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.244 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.246 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.246 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.248 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.248 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.250 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.250 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.252 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.252 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.254 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.254 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.254 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.256 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.256 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.256 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.258 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.260 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.260 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.262 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.262 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.262 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.264 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.264 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.266 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.266 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.268 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.268 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.270 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.270 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.272 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.272 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.274 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.274 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.276 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.276 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.278 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.278 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.280 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.280 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.282 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.282 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.284 - I/SCCPMSG      : send_message        : [17]          -> LINE_STAT_REQ             (msgid:11)
00:01:11:08.284 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.284 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.286 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.286 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.286 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.288 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.290 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.290 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.292 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.292 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.292 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.294 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.294 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.296 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.296 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.298 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.298 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.300 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.300 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.302 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.302 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.304 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.304 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.306 - I/SCCPMSG      : send_message        : [17]          -> SPEEDDIAL_STAT_REQ        (msgid:10)
00:01:11:08.306 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.306 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.308 - I/platform_send: sock(17), buf(0x94d24818), len(16)
00:01:11:08.314 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.314 - I/
00:01:11:08.316 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 24:0:204
00:01:11:08.316 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.316 - I/
00:01:11:08.316 - I/SCCP    1    : push_tcp            : recv[17] <- DISPLAY_PROMPT_STATUS_V2[0x145] 24:0:204
00:01:11:08.318 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:08.318 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:08.320 - I/
00:01:11:08.320 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PROMPT_STATUS[0x113] 12:0:204
00:01:11:08.320 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:08.322 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:08.322 - I/
00:01:11:08.322 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:204
00:01:11:08.324 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.324 - I/
00:01:11:08.324 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:204
00:01:11:08.326 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.326 - I/
00:01:11:08.326 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:204
00:01:11:08.328 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.328 - I/
00:01:11:08.328 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:204
00:01:11:08.330 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.332 - I/
00:01:11:08.332 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:204
00:01:11:08.332 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.334 - I/sapp_sccp_main2()- sapp_sccp_nready(7)
00:01:11:08.334 - I/
00:01:11:08.334 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.334 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= 100, fqdn= 100
00:01:11:08.334 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.336 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.336 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.338 - I/platform_send: sock(17), buf(0x94d24728), len(16)
00:01:11:08.340 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:11:08.340 - I/
00:01:11:08.340 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:08.340 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= DISPLAY_PROMPT_STATUS_V2
00:01:11:08.342 - I/SAPP   : 0:0: sapp_prompt              
00:01:11:08.342 - I/sapp_sapp_prompt(): PSCCP_EVT_PROMPT
00:01:11:08.346 - I/sapp_sccp_main2()- sapp_sccp_nready(5)
00:01:11:08.346 - I/
00:01:11:08.348 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:08.348 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PROMPT_STATUS
00:01:11:08.348 - I/SAPP   : 0:0: sapp_clearprompt         
00:01:11:08.348 - I/sapp_sapp_clearprompt(): PSCCP_EVT_CLEARPROMPT
00:01:11:08.354 - I/sapp_sccp_main2()- sapp_sccp_nready(4)
00:01:11:08.354 - I/
00:01:11:08.356 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.356 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.356 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.356 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.358 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.358 - I/platform_send: sock(17), buf(0x94d24840), len(16)
00:01:11:08.360 - I/sapp_sccp_main2()- sapp_sccp_nready(3)
00:01:11:08.362 - I/
00:01:11:08.362 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.362 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.362 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.362 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.364 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.364 - I/platform_send: sock(17), buf(0x94d248b8), len(16)
00:01:11:08.366 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:11:08.366 - I/
00:01:11:08.366 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.368 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.368 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.368 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.370 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.370 - I/platform_send: sock(17), buf(0x94d24958), len(16)
00:01:11:08.372 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:08.372 - I/
00:01:11:08.374 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.374 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.374 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.374 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.376 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.376 - I/platform_send: sock(17), buf(0x94d24890), len(16)
00:01:11:08.378 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.378 - I/
00:01:11:08.380 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.380 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.380 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.382 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.382 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.382 - I/platform_send: sock(17), buf(0x94d246d8), len(16)
00:01:11:08.386 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(23), PSCCP_EVT_PROMPT...
00:01:11:08.386 - I/TSTN> ln(0), call(0)...
00:01:11:08.386 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(8), PSCCP_EVT_CLEARPROMPT...
00:01:11:08.388 - I/TSTN> ln(0), call(0)...
00:01:11:08.392 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.394 - I/
00:01:11:08.394 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.394 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.396 - I/
00:01:11:08.396 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.396 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.398 - I/
00:01:11:08.398 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.400 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.400 - I/
00:01:11:08.402 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.402 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.402 - I/
00:01:11:08.404 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.404 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.404 - I/
00:01:11:08.404 - I/SCCP    1    : push_tcp            : recv[17] <- LINE_STAT_V2[0x147] 16:0:784
00:01:11:08.406 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_LINE_STAT_RES_V2.
00:01:11:08.406 - I/
00:01:11:08.406 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.408 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.408 - I/
00:01:11:08.410 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.410 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.412 - I/
00:01:11:08.412 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.412 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.412 - I/
00:01:11:08.414 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.414 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.416 - I/
00:01:11:08.416 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.416 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.416 - I/
00:01:11:08.418 - I/SCCP    1    : push_tcp            : recv[17] <- SPEEDDIAL_STAT_V2[0x149] 12:0:784
00:01:11:08.418 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_SPEEDDIAL_STAT_RES_V2.
00:01:11:08.418 - I/
00:01:11:08.420 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:784
00:01:11:08.420 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.422 - I/
00:01:11:08.422 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:784
00:01:11:08.422 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.424 - I/
00:01:11:08.424 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:784
00:01:11:08.424 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.424 - I/
00:01:11:08.426 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:784
00:01:11:08.426 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.426 - I/
00:01:11:08.428 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:784
00:01:11:08.428 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.430 - I/sapp_sccp_main2()- sapp_sccp_nready(16)
00:01:11:08.430 - I/
00:01:11:08.430 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.432 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.432 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.432 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.434 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.434 - I/platform_send: sock(17), buf(0x94d24908), len(16)
00:01:11:08.436 - I/sapp_sccp_main2()- sapp_sccp_nready(15)
00:01:11:08.436 - I/
00:01:11:08.436 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.436 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.436 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.438 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.440 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.440 - I/platform_send: sock(17), buf(0x94d249a8), len(16)
00:01:11:08.442 - I/sapp_sccp_main2()- sapp_sccp_nready(14)
00:01:11:08.442 - I/
00:01:11:08.442 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.444 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.444 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.444 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.446 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.446 - I/platform_send: sock(17), buf(0x94d246d8), len(16)
00:01:11:08.448 - I/sapp_sccp_main2()- sapp_sccp_nready(13)
00:01:11:08.448 - I/
00:01:11:08.448 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.448 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.450 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.450 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.452 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.452 - I/platform_send: sock(17), buf(0x94d24890), len(16)
00:01:11:08.454 - I/sapp_sccp_main2()- sapp_sccp_nready(12)
00:01:11:08.454 - I/
00:01:11:08.454 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.454 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.456 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.456 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.458 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.458 - I/platform_send: sock(17), buf(0x94d24958), len(16)
00:01:11:08.460 - I/sapp_sccp_main2()- sapp_sccp_nready(11)
00:01:11:08.460 - I/
00:01:11:08.460 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_LINE_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.462 - I/SCCPREG 1 :1 : sccpreg_sem_line_stat_res_v2: dn= , fqdn= 
00:01:11:08.462 - I/SAPP   : 0:0: sapputil_cb_linestat_res_v2
00:01:11:08.462 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.464 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.464 - I/platform_send: sock(17), buf(0x94d248b8), len(16)
00:01:11:08.466 - I/sapp_sccp_main2()- sapp_sccp_nready(10)
00:01:11:08.466 - I/
00:01:11:08.466 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.466 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.468 - I/sapp_sccp_main2()- sapp_sccp_nready(9)
00:01:11:08.468 - I/
00:01:11:08.470 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.470 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.470 - I/sapp_sccp_main2()- sapp_sccp_nready(8)
00:01:11:08.472 - I/
00:01:11:08.472 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.472 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.474 - I/sapp_sccp_main2()- sapp_sccp_nready(7)
00:01:11:08.474 - I/
00:01:11:08.474 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.474 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.476 - I/sapp_sccp_main2()- sapp_sccp_nready(6)
00:01:11:08.476 - I/
00:01:11:08.476 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.476 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.478 - I/sapp_sccp_main2()- sapp_sccp_nready(5)
00:01:11:08.478 - I/
00:01:11:08.478 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_SPEEDDIAL_STAT_RES_V2] [S_REGISTERING]
00:01:11:08.480 - I/SAPP   : 0:0: sapputil_cb_speeddialstat_res_v2
00:01:11:08.480 - I/SCCPREG 1 :1 : start_timer         : T_WF_REG_COMPLETE: 0x94dbe6b8: 0ms
00:01:11:08.480 - I/>> ln(12-12), sd(6-6), url(0-0), fe(0-0)
00:01:11:08.482 - I/sapp_sccp_main2()- sapp_sccp_nready(4)
00:01:11:08.482 - I/
00:01:11:08.482 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.482 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.482 - I/sapputil_cb_forwardstat_res(): fwdstat 1 saved during registration
00:01:11:08.484 - I/sapp_sccp_main2()- sapp_sccp_nready(3)
00:01:11:08.484 - I/
00:01:11:08.484 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.484 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.486 - I/sapputil_cb_forwardstat_res(): fwdstat 2 saved during registration
00:01:11:08.486 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:11:08.486 - I/
00:01:11:08.486 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.488 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.488 - I/sapputil_cb_forwardstat_res(): fwdstat 3 saved during registration
00:01:11:08.488 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:08.490 - I/
00:01:11:08.490 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.490 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.490 - I/sapputil_cb_forwardstat_res(): fwdstat 4 saved during registration
00:01:11:08.492 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:08.492 - I/
00:01:11:08.492 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.492 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.494 - I/sapputil_cb_forwardstat_res(): fwdstat 5 saved during registration
00:01:11:08.494 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:08.496 - I/
00:01:11:08.496 - I/SCCP    1    : push_tcp            : recv[17] <- FORWARD_STAT[0x90] 96:0:104
00:01:11:08.496 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_FORWARD_STAT_RES.
00:01:11:08.498 - I/SCCPREG 1 :1 : timeout_callback    : T_WF_REG_COMPLETE: 0x94dbe6b8
00:01:11:08.498 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.498 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.498 - I/platform_send: sock(17), buf(0x94d24688), len(16)
00:01:11:08.498 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:08.498 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:08.498 - I/platform_send: sock(17), buf(0x94d24688), len(12)
00:01:11:08.498 - I/SCCP    1    : push_event          : SCCPCM  <- E_REGISTERED.
00:01:11:08.498 - I/SCCP    1    : push_event          : SCCPREG <- SCCPREG_E_REGISTERED.
00:01:11:08.506 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:11:08.508 - I/
00:01:11:08.508 - I/SCCPREG 1    : [S_REGISTERING] [SCCPREG_E_FORWARD_STAT_RES] [S_REGISTERING]
00:01:11:08.508 - I/SAPP   : 0:0: sapputil_cb_forwardstat_res
00:01:11:08.508 - I/sapputil_cb_forwardstat_res(): fwdstat 6 saved during registration
00:01:11:08.508 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:08.510 - I/
00:01:11:08.510 - I/SCCPCM  28   : [S_REGISTERED] [E_REGISTERED] [S_REGISTERED]
00:01:11:08.512 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:11:08.512 - I/SAPP   : sapp_sessionstatus       : status= 5: cm_idx= 2
00:01:11:08.512 - I/SAPP   : sapp_sapp_sessionstatus_cm_register_complete: CM[]:0
00:01:11:08.512 - I/SAPP   : sapp_get_cmaddr_by_state : CM[10.0.0.33]:2000
00:01:11:08.512 - I/SAPP   : sapp_sapp_sessionstatus_cm_register_complete: CM[10.0.0.33]:2000
00:01:11:08.514 - I/Connected to CM
00:01:11:08.514 - I/Number of lines available: 12
00:01:11:08.514 - I/  - Line[1]: 100
00:01:11:08.514 - I/  - Line[2]: 
00:01:11:08.514 - I/  - Line[3]: 
00:01:11:08.514 - I/  - Line[4]: 
00:01:11:08.514 - I/  - Line[5]: 
00:01:11:08.516 - I/  - Line[6]: 
00:01:11:08.516 - I/  - Line[7]: 
00:01:11:08.516 - I/
00:01:11:08.516 - I/------------=={ MENU }==------------
00:01:11:08.516 - I/tstone state = OPENED
00:01:11:08.516 - I/cmaddr = [10:0:0:33:2000]
00:01:11:08.518 - I/call_state = 
00:01:11:08.518 - I/active line/call_id =    0/   0
00:01:11:08.518 - I/ts_ln  ts_callid  sccp_ln  sccp_callref  ridle  rport  c_state  m_state
00:01:11:08.518 - I/
00:01:11:08.518 - I/sapp_sapp_sessionstatus_cm_register_complete(): GAPI_STATUS_CM_REGISTER_COMPLETE
00:01:11:08.524 - I/SAPP   : sapp_sapp_sessionstatus_cm_register_complete: CM: enumeration complete
00:01:11:08.524 - I/      sinfo.lncnt(12) - data.lncnt(12)
00:01:11:08.524 - I/      sinfo.sdcnt(6) - data.sdcnt(6)
00:01:11:08.524 - I/      sinfo.fecnt(0) - data.fecnt(0)
00:01:11:08.526 - I/      sinfo.urlcnt(0) - data.urlcnt(0)
00:01:11:08.526 - I/      sinfo.skcnt(32) - data.skcnt(32)
00:01:11:08.526 - I/      sinfo.sksetcnt(13) - data.sksetcnt(13)
00:01:11:08.526 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:08.526 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:08.526 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:08.528 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:08.528 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
******* discarded 259 messages ******* 
00:01:11:13.866 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:11:13.866 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:13.868 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:13.868 - I/
00:01:11:13.868 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:11:13.868 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:11:13.868 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:13.870 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:13.872 - I/platform_send: sock(17), buf(0x94d24598), len(12)
00:01:11:13.872 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:11:13.918 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:13.918 - I/Message id 100 is not parsed!
00:01:11:13.920 - I/
00:01:11:13.920 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:11:13.922 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:11:13.922 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:13.922 - I/
00:01:11:13.922 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]
00:01:11:21.202 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:11:21.204 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:11:21.204 - I/TCP    : checked connection fail by recv event
00:01:11:21.204 - I/TCP    : socket= 18: Connection NAKed
00:01:11:21.204 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:21.206 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:21.206 - I/
00:01:11:21.206 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:11:21.208 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:11:21.208 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:11:21.208 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:21.210 - I/
00:01:11:21.210 - I/SCCPCM  25   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:11:21.210 - I/SCCPCM  1 :25: start_timer         : T_WF_CON_RETRY: 0x94dbe64c: 250ms
00:01:11:21.462 - I/SCCPCM  1 :25: timeout_callback    : T_WF_CON_RETRY: 0x94dbe64c
00:01:11:21.462 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:21.464 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:21.464 - I/
00:01:11:21.464 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:11:21.464 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:21.466 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:21.466 - I/
00:01:11:21.466 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:11:21.466 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:21.466 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:21.468 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:11:21.468 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:11:21.468 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:11:21.468 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:11:21.468 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:21.470 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:21.470 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:21.472 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:21.472 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:21.472 - I/----SCCP--cmcb #0 of type 0 using ip_addr of type 0 to connect
00:01:11:21.472 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 0
00:01:11:21.474 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.68]:2000: opening, ts_idx(0), cm_idx(0), doing_defer(0)
00:01:11:21.474 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:1 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:21.474 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:21.474 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:21.476 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:11:21.476 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:11:21.476 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35027) ok!
00:01:11:21.476 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35027), tos(96)
00:01:11:21.478 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35027
00:01:11:21.478 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:21.478 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:21.480 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.68]:2000. local_port=35027
00:01:11:21.480 - I/platform_connect_v4: addr/port=[213.140.133.68]:2000.
00:01:11:21.482 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:11:21.482 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:11:21.806 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:21.808 - I/
00:01:11:21.808 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:11:21.808 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:21.808 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:21.810 - I/
00:01:11:21.810 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:11:21.812 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:21.812 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:21.812 - I/Message id 115 is not parsed!
00:01:11:21.814 - I/
00:01:11:21.814 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:44
00:01:11:21.814 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:21.814 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:21.816 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:11:21.816 - I/
00:01:11:21.816 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:21.818 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:11:21.818 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:11:21.818 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:11:21.824 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:21.824 - I/
00:01:11:21.824 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:21.824 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:11:21.826 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:11:21.826 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:11:21.832 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:21.832 - I/
00:01:11:21.832 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:21.832 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:11:21.834 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:11:21.834 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:11:21.838 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:11:21.840 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:11:21.840 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...
00:01:11:34.046 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:11:34.046 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:11:34.048 - I/TCP    : checked connection fail by recv event
00:01:11:34.048 - I/TCP    : socket= 18: Connection NAKed
00:01:11:34.048 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:34.050 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:34.050 - I/
00:01:11:34.052 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:11:34.052 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:11:34.052 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:11:34.054 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:34.054 - I/
00:01:11:34.054 - I/SCCPCM  25   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:11:34.054 - I/SCCPCM  1 :25: start_timer         : T_WF_CON_RETRY: 0x94dbe64c: 250ms
00:01:11:34.306 - I/SCCPCM  1 :25: timeout_callback    : T_WF_CON_RETRY: 0x94dbe64c
00:01:11:34.306 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:34.308 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:34.308 - I/
00:01:11:34.308 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:11:34.308 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:34.310 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:34.310 - I/
00:01:11:34.312 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:11:34.312 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:34.312 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:34.312 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:11:34.312 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:11:34.314 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:11:34.314 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:11:34.314 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:34.314 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:34.314 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:34.316 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:34.316 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:34.316 - I/----SCCP--cmcb #0 of type 0 using ip_addr of type 0 to connect
00:01:11:34.316 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 0
00:01:11:34.318 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.68]:2000: opening, ts_idx(0), cm_idx(0), doing_defer(0)
00:01:11:34.318 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:1 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:34.318 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:34.318 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:34.320 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:11:34.320 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:11:34.322 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35028) ok!
00:01:11:34.322 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35028), tos(96)
00:01:11:34.322 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35028
00:01:11:34.322 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:34.322 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:34.324 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.68]:2000. local_port=35028
00:01:11:34.324 - I/platform_connect_v4: addr/port=[213.140.133.68]:2000.
00:01:11:34.324 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:11:34.326 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:11:43.874 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:11:43.874 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:43.874 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:43.876 - I/
00:01:11:43.876 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:11:43.876 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:11:43.878 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:11:43.878 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:11:43.878 - I/platform_send: sock(17), buf(0x94d245c0), len(12)
00:01:11:43.880 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:11:44.068 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:44.068 - I/Message id 100 is not parsed!
00:01:11:44.068 - I/
00:01:11:44.068 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:11:44.070 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:11:44.072 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:44.072 - I/
00:01:11:44.072 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]
00:01:11:46.960 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:11:46.960 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:11:46.962 - I/TCP    : checked connection fail by recv event
00:01:11:46.962 - I/TCP    : socket= 18: Connection NAKed
00:01:11:46.962 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:46.964 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.964 - I/
00:01:11:46.964 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:11:46.964 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:11:46.966 - I/SCCP    1    : push_event          : SCCPCM  <- E_ERROR.
00:01:11:46.966 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.966 - I/
00:01:11:46.968 - I/SCCPCM  25   : [S_WF_CON_RES] [E_ERROR] [S_IDLE]
00:01:11:46.968 - I/SCCPCM  1 :25: sem_wf_con_res_error: XXCM[0] 213.140.133.68:2000: error= ERROR_TCP_NAK
00:01:11:46.968 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:46.968 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:46.968 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:11:46.970 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:11:46.970 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:11:46.970 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:11:46.972 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:46.972 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:46.972 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:46.972 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:46.972 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:46.974 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:11:46.974 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.976 - I/
00:01:11:46.976 - I/SCCPREC 1    : [S_FIND_SEC] [E_DEV_NOTIFY] [S_FIND_SEC]
00:01:11:46.976 - I/SCCPREC 1 :1 : stop_timer          : 0x94dbe6dc
00:01:11:46.976 - I/SCCPREC 1 :1 : sem_find_sec_dev_notify: XXCM[0] 213.140.133.68:2000: connect failed, trying to find next
00:01:11:46.978 - I/SCCPREC 1 :1 : sem_find_sec_timeout: XXCM[1] 213.140.133.69:2000: trying to connect
00:01:11:46.978 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:46.978 - I/SCCPREC 1 :1 : start_timer         : T_WF_CONNECT: 0x94dbe6dc: 185000ms
00:01:11:46.980 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.980 - I/
00:01:11:46.980 - I/SCCPCM  26   : [S_IDLE] [E_CON_REQ] [S_WF_DNS_QUERY]
00:01:11:46.982 - I/---SCCP--push-dns-resp doing_defer as 0
00:01:11:46.982 - I/---SCCP--push-dns-resp for name "cmb" for cm 1
00:01:11:46.982 - I/TSTN> 'tstone_dns_getaddrinfo()'. query name=cmb. family=2
00:01:11:46.982 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x9557e764)dlm lookup processing -- cmb
00:01:11:46.982 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x9557e764)dlm lookup remote SSAPI_DNS_ERROR_ASYNC return
00:01:11:46.984 - I/SCCPCM  1 :26: start_timer         : T_WF_DNS_RESP: 0x94dbe5e0: 2000ms
00:01:11:46.984 - I/TSTN> 'tstone_dlm_name_to_num_cbk()'. [0] ip(213.140.133.69)
00:01:11:46.986 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. dns_resp. ipv4=213.140.133.69
00:01:11:46.986 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. (0x9557e764)dlm lookup remote(0), SSAPI_DNS_ERROR_OK return
00:01:11:46.986 - I/----SCCP---address list for host name cmb as below:
00:01:11:46.986 - I/----SCCP--addr #0: 213.140.133.69
00:01:11:46.988 - I/SCCP    1    : push_event          : SCCPCM  <- E_DNS_RESP.
00:01:11:46.988 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. done
00:01:11:46.988 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.988 - I/
00:01:11:46.990 - I/SCCPCM  26   : [S_WF_DNS_QUERY] [E_DNS_RESP] [S_WF_DNS_QUERY]
00:01:11:46.990 - I/SCCPCM  1 :26: stop_timer          : 0x94dbe5e0
00:01:11:46.992 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:46.992 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:46.992 - I/
00:01:11:46.994 - I/SCCPCM  26   : [S_WF_DNS_QUERY] [E_CON_REQ] [S_WF_CON_RES]
00:01:11:46.994 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:11:46.994 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:11:46.994 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:46.994 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:46.994 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:46.996 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:46.996 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:46.996 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:11:46.996 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:11:46.998 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:11:46.998 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:46.998 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:46.998 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:47.000 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:11:47.000 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:11:47.002 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35029) ok!
00:01:11:47.002 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35029), tos(96)
00:01:11:47.002 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35029
00:01:11:47.002 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:47.004 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:47.004 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35029
00:01:11:47.004 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:11:47.004 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:11:47.006 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:11:47.006 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RES: 0x94dbe5e0: 180000ms
00:01:11:51.872 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:11:51.874 - I/
00:01:11:51.874 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:11:51.874 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:51.876 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:51.876 - I/
00:01:11:51.876 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:11:51.876 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:51.878 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:51.878 - I/Message id 115 is not parsed!
00:01:11:51.878 - I/
00:01:11:51.878 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:44
00:01:11:51.880 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:11:51.880 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:11:51.882 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:11:51.882 - I/
00:01:11:51.882 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:51.884 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:11:51.884 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:11:51.884 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:11:51.888 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:11:51.890 - I/
00:01:11:51.890 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:51.890 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:11:51.892 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:11:51.892 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:11:51.896 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:51.898 - I/
00:01:11:51.898 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:11:51.898 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:11:51.898 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:11:51.898 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:11:51.906 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:11:51.906 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:11:51.906 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...
00:01:11:59.602 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:11:59.604 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:11:59.604 - I/TCP    : checked connection fail by recv event
00:01:11:59.604 - I/TCP    : socket= 18: Connection NAKed
00:01:11:59.604 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:11:59.606 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:59.606 - I/
00:01:11:59.606 - I/SCCPCM  26   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:11:59.606 - I/SCCPCM  1 :26: sem_tcp_events      : event= 1
00:01:11:59.608 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:11:59.608 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:59.608 - I/
00:01:11:59.608 - I/SCCPCM  26   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:11:59.610 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RETRY: 0x94dbe604: 250ms
00:01:11:59.862 - I/SCCPCM  1 :26: timeout_callback    : T_WF_CON_RETRY: 0x94dbe604
00:01:11:59.862 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:11:59.864 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:59.864 - I/
00:01:11:59.864 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:11:59.864 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:11:59.866 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:11:59.866 - I/
00:01:11:59.866 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:11:59.866 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:59.866 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:59.868 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:11:59.868 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:11:59.868 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:11:59.868 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:11:59.868 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:11:59.870 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:11:59.870 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:59.870 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:59.872 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:59.872 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:11:59.872 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:11:59.872 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:11:59.874 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:11:59.874 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:11:59.874 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:11:59.874 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:11:59.876 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:11:59.876 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35030) ok!
00:01:11:59.876 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35030), tos(96)
00:01:11:59.876 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35030
00:01:11:59.878 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:11:59.878 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:11:59.878 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35030
00:01:11:59.878 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:11:59.880 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:11:59.880 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:12:12.484 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:12:12.484 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:12:12.484 - I/TCP    : checked connection fail by recv event
00:01:12:12.484 - I/TCP    : socket= 18: Connection NAKed
00:01:12:12.486 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:12:12.486 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:12.488 - I/
00:01:12:12.488 - I/SCCPCM  26   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:12:12.488 - I/SCCPCM  1 :26: sem_tcp_events      : event= 1
00:01:12:12.488 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:12:12.490 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:12.490 - I/
00:01:12:12.490 - I/SCCPCM  26   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:12:12.490 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RETRY: 0x94dbe604: 250ms
00:01:12:12.742 - I/SCCPCM  1 :26: timeout_callback    : T_WF_CON_RETRY: 0x94dbe604
00:01:12:12.742 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:12:12.744 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:12.744 - I/
00:01:12:12.744 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:12:12.744 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:12:12.746 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:12.746 - I/
00:01:12:12.746 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:12:12.746 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:12:12.746 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:12:12.748 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:12:12.748 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:12:12.748 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:12:12.748 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:12:12.750 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:12:12.750 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:12:12.750 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:12:12.750 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:12:12.752 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:12:12.752 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:12:12.752 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:12:12.754 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:12:12.754 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:12:12.754 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:12:12.754 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:12:12.756 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:12:12.756 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:12:12.756 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35031) ok!
00:01:12:12.756 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35031), tos(96)
00:01:12:12.758 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35031
00:01:12:12.758 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:12:12.758 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:12:12.758 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35031
00:01:12:12.758 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:12:12.760 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:12:12.760 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:12:13.882 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:12:13.882 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:12:13.884 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:13.884 - I/
00:01:12:13.884 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:12:13.884 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:12:13.886 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:12:13.886 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:12:13.886 - I/platform_send: sock(17), buf(0x94d24610), len(12)
00:01:12:13.888 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:12:14.016 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:12:14.018 - I/Message id 100 is not parsed!
00:01:12:14.018 - I/
00:01:12:14.018 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:12:14.020 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:12:14.020 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:14.022 - I/
00:01:12:14.022 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]
00:01:12:21.952 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:12:21.954 - I/
00:01:12:21.954 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:32
00:01:12:21.954 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:21.956 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:21.956 - I/
00:01:12:21.956 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:32
00:01:12:21.958 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:21.958 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:21.960 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:12:21.960 - I/
00:01:12:21.960 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:21.960 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:12:21.962 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:12:21.962 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:12:21.968 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:21.968 - I/
00:01:12:21.968 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:21.968 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:12:21.968 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:12:21.968 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:12:21.976 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:12:21.976 - I/Message id 115 is not parsed!
00:01:12:21.976 - I/
00:01:12:21.978 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:12
00:01:12:21.978 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:21.978 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:21.980 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:12:21.980 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:12:21.982 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:21.982 - I/
00:01:12:21.982 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:21.984 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:12:21.984 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:12:21.984 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:12:21.990 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...
00:01:12:25.522 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:12:25.524 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:12:25.524 - I/TCP    : checked connection fail by recv event
00:01:12:25.524 - I/TCP    : socket= 18: Connection NAKed
00:01:12:25.524 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:12:25.526 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:25.526 - I/
00:01:12:25.526 - I/SCCPCM  26   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:12:25.526 - I/SCCPCM  1 :26: sem_tcp_events      : event= 1
00:01:12:25.528 - I/SCCP    1    : push_event          : SCCPCM  <- E_ERROR.
00:01:12:25.528 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:25.528 - I/
00:01:12:25.530 - I/SCCPCM  26   : [S_WF_CON_RES] [E_ERROR] [S_IDLE]
00:01:12:25.530 - I/SCCPCM  1 :26: sem_wf_con_res_error: XXCM[1] 213.140.133.69:2000: error= ERROR_TCP_NAK
00:01:12:25.530 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:12:25.530 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:12:25.532 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:12:25.532 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:12:25.532 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:12:25.532 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:12:25.534 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:12:25.534 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:12:25.534 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:12:25.534 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:12:25.536 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:12:25.536 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:12:25.536 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:25.538 - I/
00:01:12:25.538 - I/SCCPREC 1    : [S_FIND_SEC] [E_DEV_NOTIFY] [S_FIND_SEC]
00:01:12:25.538 - I/SCCPREC 1 :1 : stop_timer          : 0x94dbe6dc
00:01:12:25.538 - I/SCCPREC 1 :1 : sem_find_sec_dev_notify: XXCM[1] 213.140.133.69:2000: connect failed, trying to find next
00:01:12:25.538 - I/SCCPREC 1 :1 : sem_find_sec_timeout: No CM found to make secondary
00:01:12:25.540 - I/SCCP    1    : push_event          : SCCPREC <- E_DONE.
00:01:12:25.540 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:25.542 - I/
00:01:12:25.542 - I/SCCPREC 1    : [S_FIND_SEC] [E_DONE] [S_IDLE]
00:01:12:25.542 - I/SCCPREC 1 :1 : start_timer         : T_DEVICE_POLL: 0x94dbe6dc: 30000ms
00:01:12:43.890 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:12:43.890 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:12:43.892 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:43.892 - I/
00:01:12:43.892 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:12:43.892 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:12:43.894 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:12:43.896 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:12:43.896 - I/platform_send: sock(17), buf(0x94d24570), len(12)
00:01:12:43.896 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:12:44.094 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:12:44.094 - I/Message id 100 is not parsed!
00:01:12:44.096 - I/
00:01:12:44.096 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:12:44.096 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:12:44.098 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:44.098 - I/
00:01:12:44.098 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]
00:01:12:51.746 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:12:51.748 - I/
00:01:12:51.748 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:12:51.748 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:51.750 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:51.750 - I/
00:01:12:51.750 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:12:51.752 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:51.752 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:51.754 - I/Message id 115 is not parsed!
00:01:12:51.754 - I/
00:01:12:51.754 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:44
00:01:12:51.754 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:12:51.756 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:12:51.756 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:12:51.756 - I/
00:01:12:51.756 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:51.758 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:12:51.758 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:12:51.758 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:12:51.764 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:12:51.764 - I/
00:01:12:51.764 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:51.764 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:12:51.766 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:12:51.766 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:12:51.772 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:51.772 - I/
00:01:12:51.772 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:12:51.774 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:12:51.774 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:12:51.774 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:12:51.780 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:12:51.780 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:12:51.780 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...
00:01:12:55.542 - I/SCCPREC 1 :1 : timeout_callback    : T_DEVICE_POLL: 0x94dbe6dc
00:01:12:55.542 - I/SCCP    1    : push_event          : SCCPREC <- E_TIMEOUT.
00:01:12:55.544 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.544 - I/
00:01:12:55.544 - I/SCCPREC 1    : [S_IDLE] [E_TIMEOUT] [S_PRI_CHECK]
00:01:12:55.544 - I/SCCPREC 1 :1 : sem_pri_check       : T_DEVICE_POLL
00:01:12:55.546 - I/SCCP    1    : push_event          : SCCPREC <- E_SEC_CHECK.
00:01:12:55.546 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.546 - I/
00:01:12:55.548 - I/SCCPREC 1    : [S_PRI_CHECK] [E_SEC_CHECK] [S_SEC_CHECK]
00:01:12:55.548 - I/SCCPREC 1 :1 : sem_sec_check       : no secondary, finding
00:01:12:55.548 - I/SCCP    1    : push_event          : SCCPREC <- E_FIND_SEC.
00:01:12:55.548 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.550 - I/
00:01:12:55.550 - I/SCCPREC 1    : [S_SEC_CHECK] [E_FIND_SEC] [S_FIND_SEC]
00:01:12:55.550 - I/SCCPREC 1 :1 : sem_sec_check_find_sec: XXCM[0] 213.140.133.68:2000: trying to connect
00:01:12:55.550 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:12:55.552 - I/SCCPREC 1 :1 : start_timer         : T_WF_CONNECT: 0x94dbe6dc: 185000ms
00:01:12:55.552 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.554 - I/
00:01:12:55.554 - I/SCCPCM  25   : [S_IDLE] [E_CON_REQ] [S_WF_DNS_QUERY]
00:01:12:55.554 - I/---SCCP--push-dns-resp doing_defer as 0
00:01:12:55.554 - I/---SCCP--push-dns-resp for name "cma" for cm 0
00:01:12:55.554 - I/TSTN> 'tstone_dns_getaddrinfo()'. query name=cma. family=2
00:01:12:55.554 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x95580564)dlm lookup processing -- cma
00:01:12:55.556 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x95580564)dlm lookup remote SSAPI_DNS_ERROR_ASYNC return
00:01:12:55.556 - I/SCCPCM  1 :25: start_timer         : T_WF_DNS_RESP: 0x94dbe628: 2000ms
00:01:12:55.556 - I/TSTN> 'tstone_dlm_name_to_num_cbk()'. [0] ip(213.140.133.68)
00:01:12:55.558 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. dns_resp. ipv4=213.140.133.68
00:01:12:55.558 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. (0x95580564)dlm lookup remote(0), SSAPI_DNS_ERROR_OK return
00:01:12:55.558 - I/----SCCP---address list for host name cma as below:
00:01:12:55.558 - I/----SCCP--addr #0: 213.140.133.68
00:01:12:55.560 - I/SCCP    1    : push_event          : SCCPCM  <- E_DNS_RESP.
00:01:12:55.560 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. done
00:01:12:55.560 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.562 - I/
00:01:12:55.562 - I/SCCPCM  25   : [S_WF_DNS_QUERY] [E_DNS_RESP] [S_WF_DNS_QUERY]
00:01:12:55.562 - I/SCCPCM  1 :25: stop_timer          : 0x94dbe628
00:01:12:55.564 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:12:55.564 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:12:55.564 - I/
00:01:12:55.566 - I/SCCPCM  25   : [S_WF_DNS_QUERY] [E_CON_REQ] [S_WF_CON_RES]
00:01:12:55.566 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:12:55.566 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:12:55.566 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:12:55.566 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:12:55.568 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:12:55.568 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:12:55.568 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:12:55.568 - I/----SCCP--cmcb #0 of type 0 using ip_addr of type 0 to connect
00:01:12:55.568 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 0
00:01:12:55.570 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.68]:2000: opening, ts_idx(0), cm_idx(0), doing_defer(0)
00:01:12:55.570 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:1 ts_idx:0 cm_idx:0 doing_defer:0
00:01:12:55.570 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:12:55.570 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:12:55.572 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:12:55.572 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:12:55.574 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35032) ok!
00:01:12:55.574 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35032), tos(96)
00:01:12:55.574 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35032
00:01:12:55.574 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:12:55.574 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:12:55.576 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.68]:2000. local_port=35032
00:01:12:55.576 - I/platform_connect_v4: addr/port=[213.140.133.68]:2000.
00:01:12:55.576 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:12:55.578 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:12:55.578 - I/SCCPCM  1 :25: start_timer         : T_WF_CON_RES: 0x94dbe628: 180000ms
00:01:13:08.270 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:13:08.270 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:13:08.270 - I/TCP    : checked connection fail by recv event
00:01:13:08.272 - I/TCP    : socket= 18: Connection NAKed
00:01:13:08.274 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:13:08.274 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:08.274 - I/
00:01:13:08.274 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:13:08.274 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:13:08.276 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:13:08.276 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:08.278 - I/
00:01:13:08.278 - I/SCCPCM  25   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:13:08.278 - I/SCCPCM  1 :25: start_timer         : T_WF_CON_RETRY: 0x94dbe64c: 250ms
00:01:13:08.530 - I/SCCPCM  1 :25: timeout_callback    : T_WF_CON_RETRY: 0x94dbe64c
00:01:13:08.530 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:08.532 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:08.532 - I/
00:01:13:08.532 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:13:08.534 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:08.534 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:08.534 - I/
00:01:13:08.534 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:13:08.536 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:08.536 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:08.536 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:13:08.536 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:13:08.538 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:13:08.538 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:13:08.538 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:08.538 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:08.538 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:08.540 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:08.540 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:08.540 - I/----SCCP--cmcb #0 of type 0 using ip_addr of type 0 to connect
00:01:13:08.540 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 0
00:01:13:08.542 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.68]:2000: opening, ts_idx(0), cm_idx(0), doing_defer(0)
00:01:13:08.542 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:1 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:08.542 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:08.544 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:08.544 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:13:08.544 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:13:08.546 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35033) ok!
00:01:13:08.546 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35033), tos(96)
00:01:13:08.546 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35033
00:01:13:08.546 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:08.546 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:08.548 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.68]:2000. local_port=35033
00:01:13:08.548 - I/platform_connect_v4: addr/port=[213.140.133.68]:2000.
00:01:13:08.548 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:13:08.550 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:13:13.898 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:13:13.898 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:13.898 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:13.900 - I/
00:01:13:13.900 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:13:13.900 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:13:13.902 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:13:13.904 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:13:13.904 - I/platform_send: sock(17), buf(0x94d245e8), len(12)
00:01:13:13.904 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:13:14.002 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:13:14.004 - I/Message id 100 is not parsed!
00:01:13:14.004 - I/
00:01:13:14.004 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:13:14.004 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:13:14.006 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:14.006 - I/
00:01:13:14.006 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]
00:01:13:21.042 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:13:21.042 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:13:21.042 - I/TCP    : checked connection fail by recv event
00:01:13:21.042 - I/TCP    : socket= 18: Connection NAKed
00:01:13:21.044 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:13:21.044 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:21.046 - I/
00:01:13:21.046 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:13:21.046 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:13:21.046 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:13:21.048 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:21.048 - I/
00:01:13:21.048 - I/SCCPCM  25   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:13:21.048 - I/SCCPCM  1 :25: start_timer         : T_WF_CON_RETRY: 0x94dbe64c: 250ms
00:01:13:21.298 - I/SCCPCM  1 :25: timeout_callback    : T_WF_CON_RETRY: 0x94dbe64c
00:01:13:21.298 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:21.300 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:21.300 - I/
00:01:13:21.300 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:13:21.300 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:21.302 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:21.302 - I/
00:01:13:21.302 - I/SCCPCM  25   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:13:21.304 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:21.304 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:21.304 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:13:21.304 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:13:21.306 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:13:21.306 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:13:21.306 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:21.306 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:21.306 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:21.306 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:21.308 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:21.308 - I/----SCCP--cmcb #0 of type 0 using ip_addr of type 0 to connect
00:01:13:21.308 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 0
00:01:13:21.308 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.68]:2000: opening, ts_idx(0), cm_idx(0), doing_defer(0)
00:01:13:21.310 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:1 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:21.310 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:21.310 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:21.312 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:13:21.312 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:13:21.312 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35034) ok!
00:01:13:21.314 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35034), tos(96)
00:01:13:21.314 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35034
00:01:13:21.314 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:21.314 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:21.314 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.68]:2000. local_port=35034
00:01:13:21.316 - I/platform_connect_v4: addr/port=[213.140.133.68]:2000.
00:01:13:21.316 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:13:21.316 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:13:22.156 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:13:22.158 - I/
00:01:13:22.158 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:32
00:01:13:22.158 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:22.160 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:22.160 - I/
00:01:13:22.160 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:32
00:01:13:22.160 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:22.162 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:22.164 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:13:22.164 - I/
00:01:13:22.164 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:22.164 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:13:22.166 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:13:22.166 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:13:22.172 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:22.172 - I/
00:01:13:22.172 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:22.172 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:13:22.172 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:13:22.172 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:13:22.178 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:13:22.180 - I/Message id 115 is not parsed!
00:01:13:22.180 - I/
00:01:13:22.180 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:12
00:01:13:22.182 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:22.182 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:22.184 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:13:22.184 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:13:22.186 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:22.186 - I/
00:01:13:22.186 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:22.186 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:13:22.186 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:13:22.188 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:13:22.194 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...
00:01:13:33.842 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:13:33.842 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:13:33.842 - I/TCP    : checked connection fail by recv event
00:01:13:33.842 - I/TCP    : socket= 18: Connection NAKed
00:01:13:33.844 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:13:33.844 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.846 - I/
00:01:13:33.846 - I/SCCPCM  25   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:13:33.846 - I/SCCPCM  1 :25: sem_tcp_events      : event= 1
00:01:13:33.846 - I/SCCP    1    : push_event          : SCCPCM  <- E_ERROR.
00:01:13:33.848 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.848 - I/
00:01:13:33.848 - I/SCCPCM  25   : [S_WF_CON_RES] [E_ERROR] [S_IDLE]
00:01:13:33.848 - I/SCCPCM  1 :25: sem_wf_con_res_error: XXCM[0] 213.140.133.68:2000: error= ERROR_TCP_NAK
00:01:13:33.850 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:33.850 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:33.850 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:13:33.850 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:13:33.852 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 0
00:01:13:33.852 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.68]2000: down, state= 0
00:01:13:33.852 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:33.852 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:33.852 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:33.854 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:33.854 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:33.856 - I/SCCP    1    : push_event          : SCCPREC <- E_DEV_NOTIFY.
00:01:13:33.856 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.856 - I/
00:01:13:33.858 - I/SCCPREC 1    : [S_FIND_SEC] [E_DEV_NOTIFY] [S_FIND_SEC]
00:01:13:33.858 - I/SCCPREC 1 :1 : stop_timer          : 0x94dbe6dc
00:01:13:33.858 - I/SCCPREC 1 :1 : sem_find_sec_dev_notify: XXCM[0] 213.140.133.68:2000: connect failed, trying to find next
00:01:13:33.858 - I/SCCPREC 1 :1 : sem_find_sec_timeout: XXCM[1] 213.140.133.69:2000: trying to connect
00:01:13:33.860 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:33.860 - I/SCCPREC 1 :1 : start_timer         : T_WF_CONNECT: 0x94dbe6dc: 185000ms
00:01:13:33.860 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.860 - I/
00:01:13:33.862 - I/SCCPCM  26   : [S_IDLE] [E_CON_REQ] [S_WF_DNS_QUERY]
00:01:13:33.862 - I/---SCCP--push-dns-resp doing_defer as 0
00:01:13:33.862 - I/---SCCP--push-dns-resp for name "cmb" for cm 1
00:01:13:33.862 - I/TSTN> 'tstone_dns_getaddrinfo()'. query name=cmb. family=2
00:01:13:33.862 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x9557e764)dlm lookup processing -- cmb
00:01:13:33.864 - I/TSTN> 'tstone_dns_getaddrinfo()'. (0x9557e764)dlm lookup remote SSAPI_DNS_ERROR_ASYNC return
00:01:13:33.864 - I/SCCPCM  1 :26: start_timer         : T_WF_DNS_RESP: 0x94dbe5e0: 2000ms
00:01:13:33.866 - I/TSTN> 'tstone_dlm_name_to_num_cbk()'. [0] ip(213.140.133.69)
00:01:13:33.866 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. dns_resp. ipv4=213.140.133.69
00:01:13:33.866 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. (0x9557e764)dlm lookup remote(0), SSAPI_DNS_ERROR_OK return
00:01:13:33.866 - I/----SCCP---address list for host name cmb as below:
00:01:13:33.868 - I/----SCCP--addr #0: 213.140.133.69
00:01:13:33.868 - I/SCCP    1    : push_event          : SCCPCM  <- E_DNS_RESP.
00:01:13:33.868 - I/TSTN> 'tstone_proc_msg_dlm_name_to_num_resp()'. done
00:01:13:33.870 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.870 - I/
00:01:13:33.870 - I/SCCPCM  26   : [S_WF_DNS_QUERY] [E_DNS_RESP] [S_WF_DNS_QUERY]
00:01:13:33.870 - I/SCCPCM  1 :26: stop_timer          : 0x94dbe5e0
00:01:13:33.872 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:33.872 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:33.872 - I/
00:01:13:33.874 - I/SCCPCM  26   : [S_WF_DNS_QUERY] [E_CON_REQ] [S_WF_CON_RES]
00:01:13:33.874 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:13:33.874 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:13:33.874 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:33.876 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:33.876 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:33.876 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:33.876 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:33.878 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:13:33.878 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:13:33.878 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:13:33.878 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:33.878 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:33.880 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:33.880 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:13:33.880 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:13:33.882 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35035) ok!
00:01:13:33.882 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35035), tos(96)
00:01:13:
33.882 - I/SAPP   :[CP-6961]  sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35035
00:01:13:33.882 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:33.884 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:33.884 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35035
00:01:13:33.884 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:13:33.886 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:13:33.886 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
00:01:13:33.886 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RES: 0x94dbe5e0: 180000ms
x00:01:13:43.906 - I/SCCPCM  1 :28: timeout_callback    : T_WF_KA_ACK: 0x94dbe550
00:01:13:43.906 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:43.908 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:43.908 - I/
00:01:13:43.908 - I/SCCPCM  28   : [S_REGISTERED] [E_TIMEOUT] [S_REGISTERED]
00:01:13:43.908 - I/SCCPCM  1 :28: sem_connected_timeout: XXCM[2] 10.0.0.33:2000: retry= 1
00:01:13:43.908 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:17
00:01:13:43.910 - I/SAPP   : sapp_socket_send         : socket= 17: addr=0x0a000024:35025
00:01:13:43.910 - I/platform_send: sock(17), buf(0x94d24610), len(12)
00:01:13:43.912 - I/SCCPCM  1 :28: start_timer         : T_WF_KA_ACK: 0x94dbe550: 30000ms
00:01:13:43.914 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:13:43.916 - I/Message id 100 is not parsed!
00:01:13:43.916 - I/
00:01:13:43.916 - I/SCCP    1    : push_tcp            : recv[17] <- KEEPALIVE_ACK[0x100] 4:0:12
00:01:13:43.916 - I/SCCP    1    : push_event          : SCCPCM  <- E_KEEPALIVE_ACK.
00:01:13:43.918 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:43.918 - I/
00:01:13:43.918 - I/SCCPCM  28   : [S_REGISTERED] [E_KEEPALIVE_ACK] [S_REGISTERED]









00:01:13:46.442 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:13:46.442 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:13:46.442 - I/TCP    : checked connection fail by recv event
00:01:13:46.442 - I/TCP    : socket= 18: Connection NAKed
00:01:13:46.444 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:13:46.444 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:46.446 - I/
00:01:13:46.446 - I/SCCPCM  26   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:13:46.446 - I/SCCPCM  1 :26: sem_tcp_events      : event= 1
00:01:13:46.446 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:13:46.448 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:46.448 - I/
00:01:13:46.448 - I/SCCPCM  26   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:13:46.448 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RETRY: 0x94dbe604: 250ms

00:01:13:46.698 - I/SCCPCM  1 :26: timeout_callback    : T_WF_CON_RETRY: 0x94dbe604
00:01:13:46.698 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:46.698 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:46.700 - I/
00:01:13:46.700 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:13:46.700 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:46.702 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:46.702 - I/
00:01:13:46.702 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:13:46.704 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:46.704 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:46.704 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:13:46.704 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:13:46.706 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:13:46.706 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:13:46.706 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:46.706 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:46.706 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:46.708 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:46.708 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:46.708 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:13:46.708 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:13:46.710 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:13:46.710 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:46.710 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:46.710 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:46.712 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:13:46.712 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:13:46.712 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35036) ok!
00:01:13:46.714 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35036), tos(96)
00:01:13:46.714 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35036
00:01:13:46.714 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:46.716 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:46.716 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35036
00:01:13:46.716 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:13:46.716 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:13:46.718 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18









x00:01:13:52.036 - I/platform_recv: sock(17), buf(0x94dbebb0), len(1400)
00:01:13:52.038 - I/
00:01:13:52.038 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:13:52.038 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:52.040 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:52.040 - I/
00:01:13:52.042 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_PRIORITY_NOTIFY[0x121] 8:0:44
00:01:13:52.042 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:52.042 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:52.044 - I/Message id 115 is not parsed!
00:01:13:52.044 - I/
00:01:13:52.044 - I/SCCP    1    : push_tcp            : recv[17] <- CLEAR_NOTIFY[0x115] 4:0:44
00:01:13:52.046 - I/SCCPCC  1 :0  :0: get_cccb_by_sccpmsg : call_ref= 0, line_inst= 0 IN DEFAULT CCCB!
00:01:13:52.046 - I/SCCP    1    : push_event          : SCCPCC  <- SCCPCC_E_UPDATE_UI.
00:01:13:52.048 - I/sapp_sccp_main2()- sapp_sccp_nready(2)
00:01:13:52.048 - I/
00:01:13:52.048 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:52.048 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:13:52.048 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:13:52.050 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:13:52.054 - I/sapp_sccp_main2()- sapp_sccp_nready(1)
00:01:13:52.056 - I/
00:01:13:52.056 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:52.056 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_PRIORITY_NOTIFY
00:01:13:52.056 - I/SAPP   : 0:0: sapp_clearprioritynotify 
00:01:13:52.056 - I/sapp_sapp_clearprioritynotify(): PSCCP_EVT_CLEARPRINOTIFY
00:01:13:52.062 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:52.062 - I/
00:01:13:52.062 - I/SCCPCC  0    : [SCCPCC_S_IDLE] [SCCPCC_E_UPDATE_UI] [SCCPCC_S_IDLE]
00:01:13:52.064 - I/SCCPCC  1 :0  :0: sccpcc_sem_update_ui: msg= CLEAR_NOTIFY
00:01:13:52.064 - I/SAPP   : 0:0: sapp_clearnotify         
00:01:13:52.064 - I/sapp_sapp_clearnotify(): PSCCP_EVT_CLEARNOTIFY
00:01:13:52.070 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:13:52.070 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(7), PSCCP_EVT_CLEARPRINOTIFY...
00:01:13:52.072 - I/TSTN> 'tstone_proc_msg_psccp_info()'. evt_id(6), PSCCP_EVT_CLEARNOTIFY...










exit
Unknown command x
[CP-6961] 00:01:13:59.242 - I/platform_recv: sock(18), buf(0x94dbebb0), len(1400)
00:01:13:59.242 - I/TCP    : socket= 18: recv ERROR= 65:errno = 0x41
00:01:13:59.242 - I/TCP    : checked connection fail by recv event
00:01:13:59.242 - I/TCP    : socket= 18: Connection NAKed
00:01:13:59.244 - I/SCCP    1    : push_event          : SCCPCM  <- E_TCP_EVENTS.
00:01:13:59.244 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:59.246 - I/
00:01:13:59.246 - I/SCCPCM  26   : [S_WF_CON_RES] [E_TCP_EVENTS] [S_WF_CON_RES]
00:01:13:59.246 - I/SCCPCM  1 :26: sem_tcp_events      : event= 1
00:01:13:59.246 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_RETRY.
00:01:13:59.248 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:59.248 - I/
00:01:13:59.248 - I/SCCPCM  26   : [S_WF_CON_RES] [E_CON_RETRY] [S_WF_CON_RETRY]
00:01:13:59.248 - I/SCCPCM  1 :26: start_timer         : T_WF_CON_RETRY: 0x94dbe604: 250ms
00:01:13:59.498 - I/SCCPCM  1 :26: timeout_callback    : T_WF_CON_RETRY: 0x94dbe604
00:01:13:59.498 - I/SCCP    1    : push_event          : SCCPCM  <- E_TIMEOUT.
00:01:13:59.498 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:59.500 - I/
00:01:13:59.500 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_TIMEOUT] [S_WF_CON_RETRY]
00:01:13:59.500 - I/SCCP    1    : push_event          : SCCPCM  <- E_CON_REQ.
00:01:13:59.502 - I/sapp_sccp_main2()- sapp_sccp_nready(0)
00:01:13:59.502 - I/
00:01:13:59.502 - I/SCCPCM  26   : [S_WF_CON_RETRY] [E_CON_REQ] [S_WF_CON_RES]
00:01:13:59.502 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:59.504 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:59.504 - I/PLAT   : platform_shutdown        : socket= 18: ERROR= 22:errno = 0x16
00:01:13:59.504 - I/SAPP   : sapp_socket_close        : socket= 18->0
00:01:13:59.506 - I/SAPP   : sapp_sessionstatus       : status= 1: cm_idx= 1
00:01:13:59.506 - I/SAPP   : sapp_sapp_sessionstatus_cm_down: CM[213.140.133.69]2000: down, state= 0
00:01:13:59.506 - I/SAPP   : 0:0: sapputil_act_bak_serv_update
00:01:13:59.506 - I/sapputil_act_bak_serv_update(): acitve.idx-doing_defer(2-0); standby.idx-doing_defer(-1-0)
00:01:13:59.506 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:59.508 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:0 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:59.508 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:59.508 - I/----SCCP--cmcb #1 of type 0 using ip_addr of type 0 to connect
00:01:13:59.508 - I/SAPP   : sapp_sessionstatus       : status= 2: cm_idx= 1
00:01:13:59.508 - I/SAPP   : sapp_sapp_sessionstatus_cm_opening: CM[213.140.133.69]:2000: opening, ts_idx(1), cm_idx(1), doing_defer(0)
00:01:13:59.510 - I/[SAPP] sapp_print_cminfo. index=00 addr:213.140.133.68 port:2000 state:0 ts_idx:0 cm_idx:0 doing_defer:0
00:01:13:59.510 - I/[SAPP] sapp_print_cminfo. index=01 addr:213.140.133.69 port:2000 state:1 ts_idx:1 cm_idx:1 doing_defer:0
00:01:13:59.510 - I/[SAPP] sapp_print_cminfo. index=02 addr:10.0.0.33 port:2000 state:4 ts_idx:2 cm_idx:2 doing_defer:0
00:01:13:59.512 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:-1
00:01:13:59.512 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= -1:-1
00:01:13:59.512 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35037) ok!
00:01:13:59.514 - I/PLAT   : platform_socket_v4       : sock(18), bind port(35037), tos(96)
00:01:13:59.514 - I/SAPP   : sapp_socket_open         : socket= 18:18, addr_type=0. sec_mode=1. local_port=35037
00:01:13:59.514 - I/SAPP   : sapp_get_socket2_by_id    i=0: id= 17:18
00:01:13:59.514 - I/SAPP   : sapp_get_socket2_by_id    i=1: id= 18:18
00:01:13:59.516 - I/SAPP   : sapp_socket_connect_v6   : socket= 18: addr=[213.140.133.69]:2000. local_port=35037
00:01:13:59.516 - I/platform_connect_v4: addr/port=[213.140.133.69]:2000.
00:01:13:59.516 - I/PLAT   : connect                  : socket= 18: ERROR= 68:errno = 0x44
00:01:13:59.518 - I/SAPP   : sapp_socket_connect_v6   : NEW socket= 18
exit
[Connection to 10.0.0.36 closed by foreign host]
100.MexicoVGW#sh ephone reg
100.MexicoVGW#sh ephone registered 


ephone-1[0] Mac:F029.295A.9946 TCP socket:[1] activeLine:0 whisperLine:0 REGISTERED in SCCP ver 22/17 max_streams=1
mediaActive:0 whisper_mediaActive:0 startMedia:0 offhook:0 ringing:0 reset:0 reset_sent:0 paging 0 debug:0 caps:8 
IP:10.0.0.36 * 35025 6961  keepalive 6 max_line 18 available_line 12
button 1: cw:1 ccw:(0) 
  dn 1  number 100  CM Fallback CH1   IDLE         
Preferred Codec: g711ulaw 
Lpcor Type: none 
100.MexicoVGW#conf t
Enter configuration commands, one per line.  End with CNTL/Z.
100.MexicoVGW(config)#int fas
100.MexicoVGW(config)#int fastEthernet 4
100.MexicoVGW(config-if)#no shu
100.MexicoVGW(config-if)#no shutdown 
100.MexicoVGW(config-if)#
*Jan  2 10:02:12.677: %LINK-3-UPDOWN: Interface FastEthernet4, changed state to up


More information about the cisco-voip mailing list