15:43:20:131 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_T1_TIMEOUT, state=REGISTERED, server_index=-1, active=0, standby=1, preferMode=0 15:43:20:132 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:43:20:133 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:43:20:136 [sip] 00:38:44.134 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:43:20:146 [sip] 00:38:44.145 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:43:20:151 [sip] 00:38:44.150 tcpc0x1938018 TCP client transport created 15:43:20:154 [sip] 00:38:44.152 tcpc0x1938018 TCP transport <>:3829 is connecting to <>:5060... 15:43:20:205 [sip] 00:38:44.203 tcpc0x1938018 TCP transport <>:3829 is connected to <>:5060 15:43:20:317 [sip] 00:38:44.315 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:43:20:323 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:43:20:324 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:43:20:325 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:43:20:326 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=1, preferMode=1 15:43:20:330 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:43:20:352 [sip] 00:38:44.350 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:43:31:742 x [LC] lldpDecode(). unknown org tlv received 15:43:31:743 x [LC] lldpDecode(). unknown org tlv received 15:43:31:744 x [LC] lldpDecode(). unknown org tlv received 15:44:01:452 x [LC] lldpDecode(). unknown org tlv received 15:44:01:452 x [LC] lldpDecode(). unknown org tlv received 15:44:01:453 x [LC] lldpDecode(). unknown org tlv received 15:44:31:342 x [LC] lldpDecode(). unknown org tlv received 15:44:31:343 x [LC] lldpDecode(). unknown org tlv received 15:44:31:344 x [LC] lldpDecode(). unknown org tlv received 15:44:54:632 [sip] 00:40:18.631 pjsua_acc.c SIP outbound status for acc 0 is not active 15:44:54:636 [sip] 00:40:18.634 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:44:54:642 [sip] 00:40:18.641 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:44:54:647 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:44:54:651 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:44:54:652 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=REGISTERED, server_index=0, active=0, standby=1, preferMode=1 15:44:54:652 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:44:54:654 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:44:54 GMT 15:44:54:655 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:44:54 GMT 15:44:54:661 x [pcu] [set_svr_type][826] Bfe active_server_idx=0, serverType=0 15:44:54:662 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:44:54:664 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=0, prefer=1, server_link_status=3 15:44:54:685 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:44:54:686 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:44:54:686 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:44:54:690 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:44:54:691 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:44:54:692 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:44:54:693 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REGISTER_OK) | Cause(0) 15:44:54:694 x [CENTRAL] In func: eventHandler_registerOk(), unexpected event REGISTER_OK (cause=0) at STANDBY state 15:44:54:695 x [CENTRAL] Waiting event in STANDBY 15:45:01:336 x [LC] lldpDecode(). unknown org tlv received 15:45:01:340 x [LC] lldpDecode(). unknown org tlv received 15:45:01:340 x [LC] lldpDecode(). unknown org tlv received 15:45:20:351 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_T1_TIMEOUT, state=REGISTERED, server_index=-1, active=0, standby=1, preferMode=0 15:45:20:352 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:45:20:353 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:45:20:356 [sip] 00:40:44.354 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:45:20:366 [sip] 00:40:44.365 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:45:20:371 [sip] 00:40:44.370 tcpc0x1938018 TCP client transport created 15:45:20:374 [sip] 00:40:44.372 tcpc0x1938018 TCP transport <>:3719 is connecting to <>:5060... 15:45:20:425 [sip] 00:40:44.423 tcpc0x1938018 TCP transport <>:3719 is connected to <>:5060 15:45:20:540 [sip] 00:40:44.535 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:45:20:543 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:45:20:544 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:45:20:545 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:45:20:546 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=1, preferMode=1 15:45:20:550 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:45:20:564 [sip] 00:40:44.563 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:45:31:111 x [LC] lldpDecode(). unknown org tlv received 15:45:31:111 x [LC] lldpDecode(). unknown org tlv received 15:45:31:112 x [LC] lldpDecode(). unknown org tlv received 15:46:00:954 x [LC] lldpDecode(). unknown org tlv received 15:46:00:955 x [LC] lldpDecode(). unknown org tlv received 15:46:00:956 x [LC] lldpDecode(). unknown org tlv received 15:46:30:814 x [LC] lldpDecode(). unknown org tlv received 15:46:30:815 x [LC] lldpDecode(). unknown org tlv received 15:46:30:815 x [LC] lldpDecode(). unknown org tlv received 15:46:49:752 [sip] 00:42:13.751 pjsua_acc.c SIP outbound status for acc 0 is not active 15:46:49:756 [sip] 00:42:13.754 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:46:49:762 [sip] 00:42:13.761 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:46:49:767 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:46:49:770 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:46:49:772 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=REGISTERED, server_index=0, active=0, standby=1, preferMode=1 15:46:49:772 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:46:49:774 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:46:50 GMT 15:46:49:775 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:46:50 GMT 15:46:50:782 x [pcu] [set_svr_type][826] Bfe active_server_idx=0, serverType=0 15:46:50:782 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:46:50:784 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=0, prefer=1, server_link_status=3 15:46:50:805 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:46:50:806 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:46:50:806 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:46:50:810 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:46:50:811 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:46:50:812 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:46:50:813 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REGISTER_OK) | Cause(0) 15:46:50:814 x [CENTRAL] In func: eventHandler_registerOk(), unexpected event REGISTER_OK (cause=0) at STANDBY state 15:46:50:815 x [CENTRAL] Waiting event in STANDBY 15:47:01:547 x [LC] lldpDecode(). unknown org tlv received 15:47:01:550 x [LC] lldpDecode(). unknown org tlv received 15:47:01:551 x [LC] lldpDecode(). unknown org tlv received 15:47:21:571 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_T1_TIMEOUT, state=REGISTERED, server_index=-1, active=0, standby=1, preferMode=0 15:47:21:572 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:47:21:573 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:47:21:576 [sip] 00:42:44.574 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:47:21:586 [sip] 00:42:44.585 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:47:21:591 [sip] 00:42:44.590 tcpc0x1938018 TCP client transport created 15:47:21:594 [sip] 00:42:44.592 tcpc0x1938018 TCP transport <>:3306 is connecting to <>:5060... 15:47:21:645 [sip] 00:42:44.644 tcpc0x1938018 TCP transport <>:3306 is connected to <>:5060 15:47:21:750 [sip] 00:42:44.755 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:47:21:763 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:47:21:764 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:47:21:765 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:47:21:766 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=1, preferMode=1 15:47:21:770 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:47:21:792 [sip] 00:42:44.790 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:47:31:324 x [LC] lldpDecode(). unknown org tlv received 15:47:31:325 x [LC] lldpDecode(). unknown org tlv received 15:47:31:325 x [LC] lldpDecode(). unknown org tlv received 15:48:01:271 x [LC] lldpDecode(). unknown org tlv received 15:48:01:272 x [LC] lldpDecode(). unknown org tlv received 15:48:01:272 x [LC] lldpDecode(). unknown org tlv received 15:48:31:004 x [LC] lldpDecode(). unknown org tlv received 15:48:31:005 x [LC] lldpDecode(). unknown org tlv received 15:48:31:005 x [LC] lldpDecode(). unknown org tlv received 15:48:45:873 [sip] 00:44:08.871 pjsua_acc.c SIP outbound status for acc 0 is not active 15:48:45:876 [sip] 00:44:08.875 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:48:45:883 [sip] 00:44:08.881 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:48:45:890 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:48:45:891 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:48:45:892 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=REGISTERED, server_index=0, active=0, standby=1, preferMode=1 15:48:45:893 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:48:45:894 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:48:45 GMT 15:48:45:895 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:48:45 GMT 15:48:45:902 x [pcu] [set_svr_type][826] Bfe active_server_idx=0, serverType=0 15:48:45:903 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:48:45:904 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=0, prefer=1, server_link_status=3 15:48:45:925 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:48:45:926 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:48:45:930 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:48:45:930 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:48:45:932 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:48:45:932 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:48:45:934 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REGISTER_OK) | Cause(0) 15:48:45:934 x [CENTRAL] In func: eventHandler_registerOk(), unexpected event REGISTER_OK (cause=0) at STANDBY state 15:48:45:935 x [CENTRAL] Waiting event in STANDBY 15:49:00:765 x [LC] lldpDecode(). unknown org tlv received 15:49:00:766 x [LC] lldpDecode(). unknown org tlv received 15:49:00:766 x [LC] lldpDecode(). unknown org tlv received 15:49:21:791 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_T1_TIMEOUT, state=REGISTERED, server_index=-1, active=0, standby=1, preferMode=0 15:49:21:792 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:49:21:793 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:49:21:796 [sip] 00:44:44.794 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:49:21:806 [sip] 00:44:44.805 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:49:21:811 [sip] 00:44:44.810 tcpc0x1938018 TCP client transport created 15:49:21:814 [sip] 00:44:44.813 tcpc0x1938018 TCP transport <>:3239 is connecting to <>:5060... 15:49:21:865 [sip] 00:44:44.864 tcpc0x1938018 TCP transport <>:3239 is connected to <>:5060 15:49:21:980 [sip] 00:44:44.975 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:49:21:983 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:49:21:984 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:49:21:985 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:49:21:986 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=1, preferMode=1 15:49:21:990 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:49:22:004 [sip] 00:44:45.003 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:49:30:736 x [LC] lldpDecode(). unknown org tlv received 15:49:30:736 x [LC] lldpDecode(). unknown org tlv received 15:49:30:740 x [LC] lldpDecode(). unknown org tlv received 15:50:00:605 x [LC] lldpDecode(). unknown org tlv received 15:50:00:606 x [LC] lldpDecode(). unknown org tlv received 15:50:00:607 x [LC] lldpDecode(). unknown org tlv received 15:50:30:543 x [LC] lldpDecode(). unknown org tlv received 15:50:30:544 x [LC] lldpDecode(). unknown org tlv received 15:50:30:544 x [LC] lldpDecode(). unknown org tlv received 15:50:40:993 [sip] 00:46:03.991 pjsua_acc.c SIP outbound status for acc 0 is not active 15:50:40:996 [sip] 00:46:03.995 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:50:41:003 [sip] 00:46:04.001 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:50:41:010 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:50:41:011 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:50:41:012 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=REGISTERED, server_index=0, active=0, standby=1, preferMode=1 15:50:41:013 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:50:41:014 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:50:40 GMT 15:50:41:015 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:50:40 GMT 15:50:40:022 x [pcu] [set_svr_type][826] Bfe active_server_idx=0, serverType=0 15:50:40:023 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:50:40:024 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=0, prefer=1, server_link_status=3 15:50:40:045 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:50:40:046 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:50:40:050 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:50:40:051 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:50:40:052 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:50:40:052 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:50:40:053 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REGISTER_OK) | Cause(0) 15:50:40:054 x [CENTRAL] In func: eventHandler_registerOk(), unexpected event REGISTER_OK (cause=0) at STANDBY state 15:50:40:055 x [CENTRAL] Waiting event in STANDBY 15:50:59:451 x [LC] lldpDecode(). unknown org tlv received 15:50:59:452 x [LC] lldpDecode(). unknown org tlv received 15:50:59:453 x [LC] lldpDecode(). unknown org tlv received 15:51:21:011 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_T1_TIMEOUT, state=REGISTERED, server_index=-1, active=0, standby=1, preferMode=0 15:51:21:012 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:51:21:013 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:51:21:016 [sip] 00:46:45.014 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:51:21:026 [sip] 00:46:45.025 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:51:21:031 [sip] 00:46:45.030 tcpc0x1938018 TCP client transport created 15:51:21:034 [sip] 00:46:45.032 tcpc0x1938018 TCP transport <>:3309 is connecting to <>:5060... 15:51:21:084 [sip] 00:46:45.083 tcpc0x1938018 TCP transport <>:3309 is connected to <>:5060 15:51:21:196 [sip] 00:46:45.195 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:51:21:202 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:51:21:203 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:51:21:204 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:51:21:205 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=1, preferMode=1 15:51:21:206 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:51:21:232 [sip] 00:46:45.231 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:51:29:311 x [LC] lldpDecode(). unknown org tlv received 15:51:29:311 x [LC] lldpDecode(). unknown org tlv received 15:51:29:312 x [LC] lldpDecode(). unknown org tlv received 15:51:59:021 x [LC] lldpDecode(). unknown org tlv received 15:51:59:021 x [LC] lldpDecode(). unknown org tlv received 15:51:59:022 x [LC] lldpDecode(). unknown org tlv received 15:52:28:873 x [LC] lldpDecode(). unknown org tlv received 15:52:28:874 x [LC] lldpDecode(). unknown org tlv received 15:52:28:875 x [LC] lldpDecode(). unknown org tlv received 15:52:41:011 [sip] 00:48:05.010 pjsua_acc.c SIP registration failed, status=408 (Request Timeout) 15:52:41:015 [sip] 00:48:05.014 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : Request Timeout, status=408 15:52:41:021 [sip] 00:48:05.020 pjcu.c [pjcu_on_reg_state2():831] NO register rdata 15:52:41:025 [sip] 00:48:05.024 pjcu.c [pjcu_on_reg_state2():866]#### Has pool created for register no rdata, release it##### 15:52:41:031 [sip] 00:48:05.030 pjcu.c [pjcu_rpt_ka_status][774] target(<>), status=0, id=1 15:52:41:035 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:52:41:036 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:41:040 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_TIMEOUT, state=REGISTERED, server_index=0, active=0, standby=1, preferMode=1 15:52:41:041 w [pcu] [normalRegTimeOutHandler][2198]normalRegTimeOutHandler, eid=0, svr_idx=0, server_link_status=3 15:52:41:041 w [pcu] [pcu_set_active_server_index] active_server_idx old=0, new=999 15:52:41:042 x [pcu] PCU state transit REGISTERED --> NEED_FAILOVER 15:52:41:044 x [pcu] [pcu_do_failover][291]server_idx=1, enable_flag[server_idx]=1, alive_flag[server_idx]=0, failover_pending_id=-1 15:52:41:045 x [pcu] pcu_do_failover(), eid=0, failover to CUCM, keep mwi!! 15:52:41:046 x [pcu] [pcu_do_register][201] index=1, svr=<>:5060!! 15:52:41:050 x [pcu] [pcu_do_register][210] svr_addr=<>, svr_port=5060, g_sip_server_info.all_sip_server[server_idx]=<>!! 15:52:41:051 x [pcu] [pcu_do_register][232] release all connections before failover or fallback 15:52:41:053 w [pcu] Enter func: _pcu_start(), do eid(0) PCU start, b_fallback=0, normalStart=0, useDeferMode=0!! 15:52:41:054 x [pcu] [_pcu_start][815]1 acc_data.register_server_uri=<>:5060 15:52:41:055 x [pcu] [_pcu_start][817]2 acc_data.register_server_uri=<> 15:52:41:060 x [pcu] _pcu_start(897) reg_server_idx=1, acc_data.register_server_uri=<>, acc_data.proxy_info[1].server_port=5060 15:52:41:061 x [pcu] _pcu_start(903) reg_server_idx=1, acc_data.register_server_uri=<>:5060 15:52:41:076 x [pcu] [pcux_2_pcu_notify_cb():916] pcux_2_pcu_notify_cb, cid=65535, e_NtyId=21 15:52:41:076 w [pcu] [pcu_set_standby_server_index] standby_server_idx old=1, new=999 15:52:41:080 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:52:41:081 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 21 15:52:41:082 f [ipps] Err, remoteNtyEvtProcess() line2416 15:52:41:084 [sip] 00:48:05.082 pjcu.c pjcuRcvHandler(KA), KA_UNREG, eid=0, p1=NULL 15:52:41:141 [sip] 00:48:05.140 pjcu.c [pjcu_reconfig_acc_for_sipserver():724] pjsua_acc_del 0 15:52:41:143 [sip] 00:48:05.142 pjsua_acc.c Account id 0 deleted 15:52:41:145 [sip] 00:48:05.144 pjcu.c pjcuRcvHandler(CONN), REGISTER, eid=0, cid=-1 15:52:41:156 [sip] 00:48:05.155 tcpc0x1928018 TCP transport destroyed normally, remote:<>:5060 15:52:41:212 [sip] 00:48:05.210 pjcu.c [PJCU_ProcConnEvt():2758] case FSIP_CORE_REGISTER, PJCU_TASK_ID(0), eid(0) 15:52:41:215 [sip] 00:48:05.213 pjcu_entity.c [pjcu_getChanHandleByEid():363] Get channel id by endpoint id (0) fail 15:52:41:216 [sip] 00:48:05.215 pjcu.c [pjcu_config_acc():634] eid(0) is not mapping with pjcu accid, add a new account 15:52:41:222 [sip] 00:48:05.221 pjsua_acc.c Account "Test 3905 <>">@<>:5060> added with id 0 15:52:41:233 [sip] 00:48:05.231 sip_transport. Transport tcpc0x1928018 registered: type=TCP 15:52:41:234 [sip] 00:48:05.233 tcpc0x1928018 TCP client transport created 15:52:41:240 [sip] 00:48:05.236 tcpc0x1928018 TCP transport <>:3993 is connecting to <>:5060... 15:52:41:250 [sip] 00:48:05.246 pjsua_acc.c Registration sent 15:52:41:253 [sip] 00:48:05.251 pjcu.c [pjcu_config_acc():649] Add a new entity eid(0) mapping acc_id(0)("Test 3905 <>">@<>:5060>) 15:52:41:290 [sip] 00:48:05.286 tcpc0x1928018 TCP transport <>:3993 is connected to <>:5060 15:52:41:481 [sip] 00:48:05.476 pjsua_acc.c SIP outbound status for acc 0 is not active 15:52:41:484 [sip] 00:48:05.483 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:52:41:491 [sip] 00:48:05.487 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:52:41:495 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:52:41:496 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:41:500 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:41:501 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=NEED_FAILOVER, server_index=1, active=999, standby=999, preferMode=1 15:52:41:502 w [pcu] [pcu_set_active_server_index] active_server_idx old=999, new=1 15:52:41:503 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:52:41:504 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:52:41 GMT 15:52:41:505 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:52:41 GMT 15:52:41:512 x [pcu] [set_svr_type][826] Bfe active_server_idx=1, serverType=0 15:52:41:513 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:52:41:514 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=1, prefer=1, server_link_status=3 15:52:41:515 w [pcu] [normalRegOkHandler][2155] No pending failover/fallback action 15:52:41:516 x [pcu] PCU state transit NEED_FAILOVER --> FIND_FALLBACK_SERVER 15:52:41:517 x [pcu] [pcu_send_keep_alive():494] index(2) > PJSUA_ACC_MAX_PROXIES or g_sip_server_info.enable_flag[2]=FALSE 15:52:41:520 x [pcu] [normalRegOkHandler][2183]To Detect the higher priority server, current active_index=1 15:52:41:521 w [pcu] [pcu_detect_fallback_server][612]detect high priority from 0 to 0 15:52:41:522 x [pcu] pcu_send_keep_alive(511) index=0, isSrst=0, server_port=5060 15:52:41:523 w [pcu] [pcu_send_keep_alive][520] index=0, prefer=1, highPriority=1, polling_server_string=<>:5060;transport=tcp 15:52:41:545 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:52:41:546 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:52:41:547 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:52:41:550 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:52:41:551 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:52:41:552 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:52:41:555 [sip] 00:48:05.553 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:52:41:555 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REGISTER_OK) | Cause(0) 15:52:41:556 x [CENTRAL] In func: eventHandler_registerOk(), unexpected event REGISTER_OK (cause=0) at STANDBY state 15:52:41:560 x [CENTRAL] Waiting event in STANDBY 15:52:41:627 [sip] 00:48:05.625 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:52:41:631 [sip] 00:48:05.630 tcpc0x1938018 TCP client transport created 15:52:41:635 [sip] 00:48:05.633 tcpc0x1938018 TCP transport <>:3282 is connecting to <>:5060... 15:52:41:685 [sip] 00:48:05.684 tcpc0x1938018 TCP transport <>:3282 is connected to <>:5060 15:52:41:800 [sip] 00:48:05.796 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:52:41:803 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:52:41:804 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:41:805 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=FIND_FALLBACK_SERVER, server_index=0, active=1, standby=999, preferMode=1 15:52:41:806 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=0, prefer=1, server_link_status=6 15:52:41:810 w [pcu] [keepAliveOkHandler][2466] high priority server(0) KA_OK, prefer=1, server_connect_status=6 15:52:41:811 w [pcu] [keepAliveOkHandler][2525] current active server(1) is not SRST 15:52:41:812 x [pcu] PCU state transit FIND_FALLBACK_SERVER --> WAIT_FALLBACK 15:52:41:813 f [pcu] [keepAliveOkHandler][2530]Do fallback....server_index=0 15:52:41:813 x [pcu] pcu_do_fall_back(595) index=0, g_sip_server_info.all_sip_server[0]=<>:5060 15:52:41:815 x [pcu] pcu_do_fall_back(597) index=0, g_sip_server_info.all_sip_server[0]=<>:5060 15:52:41:815 x [pcu] [pcu_polling_make_token_register():334] sip_server=<>:5060;transport=tcp 15:52:41:827 [sip] 00:48:05.825 pjcu.c pjcuRcvHandler(KA), KA_TOKEN_REG, eid=0, p1=<>:5060;transport=tcp 15:52:41:896 [sip] 00:48:05.894 pjcu_ka.c [pjcu_ka_token_reg_callback][139]sip_token->sip_server=<>:5060;transport=tcp 15:52:41:902 [sip] 00:48:05.901 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=4 15:52:41:905 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:52:41:906 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:41:910 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_TOKEN_REGISTER_OK, state=WAIT_FALLBACK, server_index=0, active=1, standby=999, preferMode=1 15:52:41:911 w [pcu] [tokenRegOkHandler][2740]tokenRegOkHandler, eid=0, svr_idx=0 15:52:41:913 x [pcu] [tokenRegOkHandler][2753]SIP_TOKEN_REGISTER_OK, server_index=0, fallbackCandidate=-1 15:52:41:914 x [pcu] [tokenRegOkHandler][2756] g_sip_server_info2.isSRST[0]=0 15:52:41:914 x [pcu] [tokenRegOkHandler][2766]current active is not SRST, so set flag. 15:52:41:916 w [pcu] [pcu_set_active_server_index] active_server_idx old=1, new=999 15:52:41:920 x [pcu] [tokenRegOkHandler][2795]Fallback to first server 15:52:41:921 x [pcu] PCU state transit WAIT_FALLBACK --> REGISTERING 15:52:41:922 x [pcu] [pcu_do_register][201] index=0, svr=<>:5060!! 15:52:41:923 x [pcu] [pcu_do_register][210] svr_addr=<>, svr_port=5060, g_sip_server_info.all_sip_server[server_idx]=<>!! 15:52:41:924 x [pcu] [pcu_do_register][232] release all connections before failover or fallback 15:52:41:926 w [pcu] Enter func: _pcu_start(), do eid(0) PCU start, b_fallback=1, normalStart=0, useDeferMode=0!! 15:52:41:926 x [pcu] [_pcu_start][815]1 acc_data.register_server_uri=<>:5060 15:52:41:930 x [pcu] [_pcu_start][817]2 acc_data.register_server_uri=<> 15:52:41:933 x [pcu] _pcu_start(897) reg_server_idx=0, acc_data.register_server_uri=<>, acc_data.proxy_info[0].server_port=5060 15:52:41:934 x [pcu] _pcu_start(903) reg_server_idx=0, acc_data.register_server_uri=<>:5060 15:52:41:951 x [pcu] [pcux_2_pcu_notify_cb():916] pcux_2_pcu_notify_cb, cid=65535, e_NtyId=21 15:52:41:952 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:52:41:953 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 21 15:52:41:953 f [ipps] Err, remoteNtyEvtProcess() line2416 15:52:41:956 [sip] 00:48:05.954 pjcu.c pjcuRcvHandler(KA), KA_UNREG, eid=0, p1=NULL 15:52:41:960 [sip] 00:48:05.956 pjcu.c [pjcu_reconfig_acc_for_sipserver():724] pjsua_acc_del 0 15:52:41:965 [sip] 00:48:05.964 pjsua_acc.c Unregistration sent 15:52:41:970 [sip] 00:48:05.966 pjsua_acc.c Account id 0 deleted 15:52:41:972 [sip] 00:48:05.971 pjcu.c pjcuRcvHandler(CONN), REGISTER, eid=0, cid=-1 15:52:42:032 [sip] 00:48:06.030 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060 15:52:42:041 [sip] 00:48:06.040 pjcu.c [PJCU_ProcConnEvt():2758] case FSIP_CORE_REGISTER, PJCU_TASK_ID(0), eid(0) 15:52:42:044 [sip] 00:48:06.043 pjcu_entity.c [pjcu_getChanHandleByEid():363] Get channel id by endpoint id (0) fail 15:52:42:046 [sip] 00:48:06.045 pjcu.c [pjcu_config_acc():634] eid(0) is not mapping with pjcu accid, add a new account 15:52:42:052 [sip] 00:48:06.050 pjsua_acc.c Account "Test 3905 <>">@<>:5060> added with id 0 15:52:42:063 [sip] 00:48:06.061 sip_transport. Transport tcpc0x198bf5c registered: type=TCP 15:52:42:065 [sip] 00:48:06.063 tcpc0x198bf5c TCP client transport created 15:52:42:070 [sip] 00:48:06.066 tcpc0x198bf5c TCP transport <>:3902 is connecting to <>:5060... 15:52:42:080 [sip] 00:48:06.076 pjsua_acc.c Registration sent 15:52:42:083 [sip] 00:48:06.081 pjcu.c [pjcu_config_acc():649] Add a new entity eid(0) mapping acc_id(0)("Test 3905 <>">@<>:5060>) 15:52:42:121 [sip] 00:48:06.117 tcpc0x198bf5c TCP transport <>:3902 is connected to <>:5060 15:52:47:972 [sip] 00:48:11.971 tcpc0x1928018 TCP transport destroyed normally, remote:<>:5060 15:52:48:081 [sip] 00:48:12.080 pjsua_acc.c SIP registration failed, status=408 (Request Timeout) 15:52:48:085 [sip] 00:48:12.084 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : Request Timeout, status=408 15:52:48:091 [sip] 00:48:12.090 pjcu.c [pjcu_on_reg_state2():831] NO register rdata 15:52:48:095 [sip] 00:48:12.094 pjcu.c [pjcu_on_reg_state2():866]#### Has pool created for register no rdata, release it##### 15:52:48:101 [sip] 00:48:12.100 pjcu.c [pjcu_rpt_ka_status][774] target(<>), status=0, id=1 15:52:48:105 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:52:48:106 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:48:110 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_TIMEOUT, state=REGISTERING, server_index=0, active=999, standby=999, preferMode=1 15:52:48:111 w [pcu] [normalRegTimeOutHandler][2198]normalRegTimeOutHandler, eid=0, svr_idx=0, server_link_status=0 15:52:48:111 x [pcu] PCU state transit REGISTERING --> NEED_FAILOVER 15:52:48:112 w [pcu] [normalRegTimeOutHandler][2274] Try to register to server(1) 15:52:48:113 x [pcu] [pcu_do_failover][291]server_idx=1, enable_flag[server_idx]=1, alive_flag[server_idx]=0, failover_pending_id=-1 15:52:48:114 x [pcu] pcu_do_failover(), eid=0, failover to CUCM, keep mwi!! 15:52:48:115 x [pcu] [pcu_do_register][201] index=1, svr=<>!! 15:52:48:116 x [pcu] [pcu_do_register][210] svr_addr=<>, svr_port=5060, g_sip_server_info.all_sip_server[server_idx]=<>!! 15:52:48:120 x [pcu] [pcu_do_register][232] release all connections before failover or fallback 15:52:48:122 w [pcu] Enter func: _pcu_start(), do eid(0) PCU start, b_fallback=0, normalStart=0, useDeferMode=0!! 15:52:48:123 x [pcu] [_pcu_start][815]1 acc_data.register_server_uri=<>:5060 15:52:48:124 x [pcu] [_pcu_start][817]2 acc_data.register_server_uri=<> 15:52:48:126 x [pcu] _pcu_start(897) reg_server_idx=1, acc_data.register_server_uri=<>, acc_data.proxy_info[1].server_port=5060 15:52:48:130 x [pcu] _pcu_start(903) reg_server_idx=1, acc_data.register_server_uri=<>:5060 15:52:48:144 x [pcu] [pcux_2_pcu_notify_cb():916] pcux_2_pcu_notify_cb, cid=65535, e_NtyId=21 15:52:48:145 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:52:48:146 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 21 15:52:48:150 f [ipps] Err, remoteNtyEvtProcess() line2416 15:52:48:152 [sip] 00:48:12.151 pjcu.c pjcuRcvHandler(KA), KA_UNREG, eid=0, p1=NULL 15:52:48:200 [sip] 00:48:12.196 pjcu.c [pjcu_on_reg_state2][914]Need to pcu_rptRemoteRestart() 15:52:48:203 [sip] 00:48:12.202 pjcu_pjsip_api [pcu_rptRemoteRestart():2650]: report restart remotely 15:52:48:210 x [pcu] pcuRcvHandler(CALL), NTY_EV, eid=0, cid=-1, 15:52:48:212 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:52:48:212 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 12 15:52:48:213 x [CENTRAL] IPPS CB function(Restart) is called 15:52:48:214 x [CENTRAL] Enter FSM: State(STANDBY) | Event(RESTART) | Cause(0) 15:52:48:215 [ipps] ----- UIU: UI_END_ALL_CALL, lid=0, cid=65535 ----- 15:52:48:216 f [ipps] sipesm, ev=EPCMD_END_ALL_CALL, state(LNST_ONHOOK), eid=0, cid=65535) 15:52:48:217 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:52:48:221 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 34 15:52:48:221 w [ipps] [remoteNtyEvtProcess][2397] No paging handle active 15:52:48:223 [ipps] ----- SYS: SY_STOP_EV ----- 15:52:48:224 x [pcu] PCU state transit NEED_FAILOVER --> INIT 15:52:48:225 [ipps] Enter func: ipps_sysUnConfigure() to un-configure external modules !! 15:52:48:226 x [MCU] msgData.mcuCom =2, addr(0x0ff5800) = 60 15:52:48:232 x [pcu] PCU state: duplicate transition to INIT 15:52:48:234 [ipps] ----- SYS: SY_UNCONFIGURE_EV ----- 15:52:48:235 [ipps] In func: mlcu_cleanLineInfo(), clean line info for unConfigure! 15:52:48:236 [ipps] Exit func: ipps_sysUnConfigure(), finish un-configuration !! 15:52:48:237 w [NTP] Need stop NTP 15:52:48:240 w [NTP] NTP task has not been created 15:52:48:241 x [CENTRAL] State transit STANDBY --> PROVISIONING 15:52:48:273 x [CENTRAL] Start provision 15:52:48:274 x [CENTRAL] Waiting event in PROVISIONING 15:52:48:276 x [CENTRAL] Provision CB function is called (6) 15:52:48:276 x [CENTRAL] Enter FSM: State(PROVISIONING) | Event(PROV_CANCELED) | Cause(0) 15:52:48:280 x [CENTRAL] In func: eventHandler_suspendRet(), provision canceled! 15:52:48:281 x [CENTRAL] Waiting event in PROVISIONING 15:52:48:393 w [PROVISION] provCfg_prepareTftpServer() selection group=(OPTION150, NONE) 15:52:48:470 [sip] 00:48:12.466 pjsua_acc.c Registration sent 15:52:48:491 [sip] 00:48:12.490 pjcu.c [pjcu_reconfig_acc_for_sipserver():724] pjsua_acc_del 0 15:52:48:494 [sip] 00:48:12.493 sip_reg.c Unable to send request, regc has another transaction pending 15:52:48:496 [sip] 00:48:12.495 pjsua_acc.c Unable to create/send REGISTER: Unknown error 171001 [status=171001] 15:52:48:501 [sip] 00:48:12.500 pjsua_acc.c Account id 0 deleted 15:52:48:503 [sip] 00:48:12.502 pjcu.c pjcuRcvHandler(CONN), REGISTER, eid=0, cid=-1 15:52:48:571 [sip] 00:48:12.570 pjcu.c [PJCU_ProcConnEvt():2758] case FSIP_CORE_REGISTER, PJCU_TASK_ID(0), eid(0) 15:52:48:574 [sip] 00:48:12.573 pjcu_entity.c [pjcu_getChanHandleByEid():363] Get channel id by endpoint id (0) fail 15:52:48:576 [sip] 00:48:12.575 pjcu.c [pjcu_config_acc():634] eid(0) is not mapping with pjcu accid, add a new account 15:52:48:582 [sip] 00:48:12.580 pjsua_acc.c Account "Test 3905 <>">@<>:5060> added with id 0 15:52:48:592 [sip] 00:48:12.591 sip_transport. Transport tcpc0x1982018 registered: type=TCP 15:52:48:594 [sip] 00:48:12.593 tcpc0x1982018 TCP client transport created 15:52:48:600 [sip] 00:48:12.595 tcpc0x1982018 TCP transport <>:3243 is connecting to <>:5060... 15:52:48:610 [sip] 00:48:12.606 pjsua_acc.c Registration sent 15:52:48:612 [sip] 00:48:12.611 pjcu.c [pjcu_config_acc():649] Add a new entity eid(0) mapping acc_id(0)("Test 3905 <>">@<>:5060>) 15:52:48:614 [sip] 00:48:12.613 pjcu.c pjcuRcvHandler(CONN), SHUTDOWN, eid=0, cid=-1 15:52:48:616 [sip] 00:48:12.615 pjcu.c [PJCU_ProcConnEvt():2804] case FSIP_CORE_SHUTDOWN, PJCU_TASK_ID(0), eid(0) 15:52:48:621 [sip] 00:48:12.620 pjcu.c [PJCU_ProcConnEvt():2815]pjsua_var.acc[0].subscribe_dialog.p_evsub=0x0) 15:52:48:623 w [SUU] tftp_cmd(GET), sessionId(0), rFilename(SEP08CC6830F94B.cnf.xml), dwServerIp(<>), dwPort(69), lPathFileName(/var/prov/SEP08CC6830F94B.cnf.xml), retryNum(6), maxFileSize(524288), tos(96) 15:52:48:661 [sip] 00:48:12.660 pjsua_core.c Shutting down... 15:52:48:663 [sip] 00:48:12.662 pjsua_pres.c Shutting down presence.. 15:52:48:665 [sip] 00:48:12.664 pjsua_kpml.c Shutting down kpml.. 15:52:48:670 [sip] 00:48:12.666 sip_reg.c Unable to send request, regc has another transaction pending 15:52:48:673 [sip] 00:48:12.671 pjsua_acc.c Unable to create/send REGISTER: Unknown error 171001 [status=171001] 15:52:48:675 [sip] 00:48:12.674 tcpc0x1982018 TCP transport <>:3243 is connected to <>:5060 25/08/2023 15:52:50 succeed to get SEP08CC6830F94B.cnf.xml 15:52:51:215 [sip] 00:48:15.214 sip_endpoint.c Message Response msg 100/REGISTER/cseq=31525 (rdata0x198c104) from <>:5060 was dropped/unhandled by any modules 15:52:52:681 [sip] 00:48:16.680 pjsua_core.c Destroying... 15:52:52:683 [sip] 00:48:16.682 sip_endpoint.c Destroying endpoing instance.. 15:52:52:684 [sip] 00:48:16.683 sip_transactio Stopping transaction layer module 15:52:52:690 [sip] 00:48:16.686 pjsua_acc.c SIP registration failed, status=503 (Service Unavailable) 15:52:52:692 [sip] 00:48:16.691 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : Service Unavailable, status=503 15:52:52:694 [sip] 00:48:16.693 pjcu.c [pjcu_on_reg_state2():831] NO register rdata 15:52:52:696 [sip] 00:48:16.695 pjcu.c [pjcu_on_reg_state2():866]#### Has pool created for register no rdata, release it##### 15:52:52:701 [sip] 00:48:16.700 pjcu.c [pjcu_rpt_ka_status][774] target(<>), status=0, id=1 15:52:52:703 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:52:52:704 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:52:705 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>, server_ip=<>, server_ip_defer=, pureIp=<> 15:52:52:706 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_TIMEOUT, state=INIT, server_index=1, active=999, standby=999, preferMode=1 15:52:52:710 w [pcu] [normalRegTimeOutHandler][2198]normalRegTimeOutHandler, eid=0, svr_idx=1, server_link_status=0 15:52:52:713 [sip] 00:48:16.712 pjsua_advsip.c PJCU advsip module unregistered ! 15:52:52:715 [sip] 00:48:16.713 sip_transactio Transaction layer module destroyed 15:52:52:722 [sip] 00:48:16.720 tcpc0x1982018 TCP transport destroyed normally, remote:<>:5060 15:52:52:724 [sip] 00:48:16.723 tcpc0x198bf5c TCP transport destroyed normally, remote:<>:5060 15:52:52:726 [sip] 00:48:16.725 tcplis:5060 SIP TCP listener destroyed 15:52:52:732 [sip] 00:48:16.730 sip_endpoint.c Endpoint 0x131446c destroyed 15:52:52:734 [sip] 00:48:16.732 pjsua_core.c PJSUA destroyed... 15:52:56:310 f [PROVISION] saveCucmArrayToConfig() i=0, szBuf=0.0.0.0 15:52:56:311 f [PROVISION] saveCucmArrayToConfig() i=0, szBuf=Directed Broadcast 15:52:56:312 f [PROVISION] saveCucmArrayToConfig() i=1, szBuf=0.0.0.0 15:52:56:312 f [PROVISION] saveCucmArrayToConfig() i=1, szBuf=Directed Broadcast 15:52:56:660 w [SUU] tftp_cmd(GET), sessionId(1), rFilename(CP3905.9-4-1SR3.loads), dwServerIp(<>), dwPort(69), lPathFileName(/var/prov/CP3905.9-4-1SR3.loads), retryNum(6), maxFileSize(524288), tos(96) 25/08/2023 15:52:56 succeed to get CP3905.9-4-1SR3.loads 15:52:56:732 x [PROVISION] image name after delete prefix= 3905.9-4-1SR3.ZZ 15:52:56:735 w [PROVISION] Needn't to update tzUpdate file. 15:52:56:752 f [i18n] : In i18nFont_initiateLayoutEngine open font file OK. 15:52:56:753 f [i18n] : In i18nFont_initiateLayoutEngine open font file filesize = 15300. 15:52:56:754 f [i18n] : In i18nFont_initiateLayoutEngine calloc file size OK. 15:52:56:755 f [i18n] : In i18nFont_initiateLayoutEngine read file size OK. 15:52:56:756 f [i18n] : In i18nFont_initiateLayoutEngine open font file FontDataSize=15300. 15:52:56:760 f [i18n] : In i18nFont_initiateLayoutEngine bufsize=3076. 15:52:56:764 f [i18n] : In i18nFont_initiateLayoutEngine call RbmpReset kret=0. 15:52:57:885 x [MCU] debug:[sc1445x_mcu_updateRecordingTone]: on_dur (425), freq (1399), lOnDur (425), rOnDur (425), (lFreq (1399), rFreq (1399) lAmp (-120), rAmp (-100), lVol (100), rVol (50)15:52:57:954 w [MCU] (ciscoTone_update): need not update securewarning/unsecurewarning tone from g3-tone 15:52:57:973 w [MCU] (ciscoTone_update): need not update securewarning/unsecurewarning tone from g3-tone 15:52:57:975 w [PROVISION] provCfg_isNeedDnldOtherFile() ------softKeyFile =SK72f64050-7ad5-4b47-9bfa-5e9ad9cd4aa9.xml 15:52:58:200 w [SUU] tftp_cmd(GET), sessionId(0), rFilename(SK72f64050-7ad5-4b47-9bfa-5e9ad9cd4aa9.xml), dwServerIp(<>), dwPort(69), lPathFileName(/var/prov/SK72f64050-7ad5-4b47-9bfa-5e9ad9cd4aa9.xml), retryNum(6), maxFileSize(524288), tos(96) 25/08/2023 15:52:58 succeed to get SK72f64050-7ad5-4b47-9bfa-5e9ad9cd4aa9.xml 15:52:59:804 x [CENTRAL] Provision CB function is called (2) 15:52:59:804 x [CENTRAL] Enter FSM: State(PROVISIONING) | Event(PROV_CFG_NO_CHANGE) | Cause(0) 15:52:59:810 x [CENTRAL] Set GARP Enable (1) 15:52:59:906 x [LC] lldpDecode(). unknown org tlv received 15:52:59:910 x [LC] lldpDecode(). unknown org tlv received 15:52:59:910 x [LC] lldpDecode(). unknown org tlv received 15:52:59:921 x [CENTRAL] DSCP value no change(96) 15:52:59:931 x [SW] switchConf_updateCfg(), Span to PC Disable : 1 15:52:59:931 x [SW] switchConf_updateCfg(), PC port Disable : 1 15:52:59:932 x [SW] switchConf_updateCfg(), PC Voice VLAN Access : 0 15:52:59:933 x [SW] switchConf_updateCfg(), SIP DSCP for Audio : 46 15:52:59:933 x [CENTRAL] vlanCandidateCheck(). 15:52:59:934 x [CENTRAL] State transit PROVISIONING --> PROVISIONED 15:52:59:935 x [CENTRAL] Waiting event in PROVISIONED 15:52:59:935 % [nwCtl] -------- rcv (RECONFIG) -------- 15:52:59:936 % [nwCtl] V4 state: READY -> READY 15:52:59:940 x [nwCtl] v6_reconfigHandler() mode=0, autocfg=1->1 15:52:59:940 % [nwCtl] V6 state: DISABLED -> DISABLED 15:52:59:941 % [nwCtl] -------- end (RECONFIG) -------- 15:52:59:942 w [CENTRAL] networkStateCb() v4Status=0x80, v6Status=0x1 15:52:59:942 x [CENTRAL] Enter FSM: State(PROVISIONED) | Event(NW_REPORT) | Cause(0) 15:52:59:943 x [CENTRAL] eventHandler_nw_report(), v4(0x80) v6(0x1), state = 5 15:52:59:944 x [CENTRAL] eventHandler_nw_report(), lastv4(0x80), lastv6(0x1), lastState = 4 15:53:00:107 x [CENTRAL] NOT (single mode to dual mode, or ipv4 only to ipv6 only, or ipv6 only to ipv4 only), register 15:53:00:120 x [CENTRAL] State transit PROVISIONED --> REGISTERING 15:53:00:142 [ipps] Enter func: ipps_sysConfigure() to configure external modules!! 15:53:00:143 x [MCU] msgData.mcuCom =2, addr(0x0ff5800) = 60 15:53:00:145 x [pcu] PCU state: duplicate transition to INIT 15:53:00:151 [ipps] Exit func: ipps_sysConfigure(), finish configuration!! 15:53:00:152 [ipps] In func: ipps_sysStart()....start service.. 15:53:00:153 [ipps] In func: mlcu_cleanLineInfo(), clean line info for unConfigure! 15:53:00:154 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:53:00:155 x [pcu] PCU state transit INIT --> REGISTERING 15:53:00:156 w [pcu] Enter func: _pcu_start(), do eid(0) PCU start, b_fallback=0, normalStart=1, useDeferMode=0!! 15:53:00:160 x [pcu] [pcuGetAccData][1341]ipMode=0, signalingMode=0, mediaMode=0, ipv4Up=1, ipv6Up=0 15:53:00:162 x [pcu] [pcuGetAccData][1378]NAME=<>, DISPLAY_NAME=Test 3905 <>, AUTH_NAME=(len=0), PW=(len=0) 15:53:00:163 x [pcu] [resolveCucmNameOrAddr][1104] deferIpMode=0, useDeferIpMode=0, *server_idx=-1 15:53:00:164 w [pcu] [resolveCucmNameOrAddr][1108] IPv4 only, the original logic... 15:53:00:165 x [pcu] [resolveCucmIPAddr][422] *updateFlag=0, *server_idx=-1, prefer=1 15:53:00:166 x [pcu] [resolveCucmIPAddr][454] CUCM0 addr=<> 15:53:00:170 x [pcu] [resolveCucmIPAddr][460] domain=<> 15:53:00:171 x [pcu] [resolveCucmIPAddr][464] tag has . in it 15:53:00:172 x [pcu] [resolveCucmIPAddr][478] query1=<> 15:53:00:172 x [pcu] [resolveCucmIPAddr][480] query2=<>.<> 15:53:00:176 x [CENTRAL] Waiting event in REGISTERING 15:53:00:216 [sip] 00:48:24.214 pjsua_core.c Init KPML module!!!!!! 15:53:00:220 [sip] 00:48:24.216 pjsua_core.c Init dlgEvent module!!!!!! 15:53:00:224 [sip] 00:48:24.222 pjsua_core.c 1 SIP worker threads created 15:53:00:226 [sip] 00:48:24.224 pjsua_core.c pjsua version 1.8.10 for i686-pc-linux-gnu initialized 15:53:00:231 w [pcu] [resolveCucmIPAddr][493] Resolved proxy_info[0].server_ip=<>, server=<>, port=5060 15:53:00:233 w [pcu] [resolveCucmIPAddr()543] Resolved Decide register URI=<>:5060 15:53:00:234 x [pcu] [resolveCucmIPAddr][454] CUCM1 addr=<> 15:53:00:235 x [pcu] [resolveCucmIPAddr][460] domain=<> 15:53:00:236 x [pcu] [resolveCucmIPAddr][464] tag has . in it 15:53:00:240 x [pcu] [resolveCucmIPAddr][478] query1=<> 15:53:00:240 x [pcu] [resolveCucmIPAddr][480] query2=<>.<> 15:53:00:245 [sip] 00:48:24.226 pjcu.c [pjcu_init():2483] SIGNALING_TYPE_IPV4, transport_data.transport_info[0].transport_port=5060 15:53:00:254 [sip] 00:48:24.252 tcplis:5060 SIP TCP listener ready for incoming connections at <>:5060 15:53:00:256 [sip] 00:48:24.255 pjsua_core.c SIP UDP socket reachable at <>:5060 15:53:00:262 [sip] 00:48:24.261 sip_transport. Transport udp0x1348814 registered: type=UDP 15:53:00:265 [sip] 00:48:24.263 udp0x1348814 SIP UDP transport started, published address is <>:5060 15:53:00:267 [sip] 00:48:24.265 pjcu.c [pjcu_init():2611] g_acc_udp_transport_id[0]=1, g_acc_udp_transport_id[1]=-1 15:53:00:315 w [pcu] [resolveCucmIPAddr][493] Resolved proxy_info[1].server_ip=<>, server=<>, port=5060 15:53:00:316 w [pcu] [resolveCucmIPAddr()569] Resolved server(1)=<>, Don't set URI 15:53:00:320 x [pcu] [pcuGetAccData][1475] Final decide signaling_addr_type=0, media_addr_type=0, useIPv6Signaling=0 15:53:00:321 x [pcu] [pcuGetAccData][1476] Final decide ipv4Addr=<>, ipv6Addr=:: 15:53:00:325 x [pcu] [polling_server_set][727] all_sip_server[0]=<>:5060, server=<>, server_ip=<> 15:53:00:326 w [pcu] [polling_server_get_from_config_system][666] Add sip server[0]: <>:5060, server_port=5060! 15:53:00:330 x [pcu] [polling_server_set][727] all_sip_server[1]=<>:5060, server=<>, server_ip=<> 15:53:00:331 w [pcu] [polling_server_get_from_config_system][666] Add sip server[1]: <>:5060, server_port=5060! 15:53:00:332 w [pcu] [_pcu_start][834]srv_idx=8, available server count=2 15:53:00:334 x [pcu] _pcu_start(897) reg_server_idx=0, acc_data.register_server_uri=<>:5060, acc_data.proxy_info[0].server_port=5060 15:53:00:335 x [pcu] _pcu_start(903) reg_server_idx=0, acc_data.register_server_uri=<>:5060 15:53:00:354 [sip] 00:48:24.352 pjcu.c pjcuRcvHandler(CONN), REGISTER, eid=0, cid=-1 15:53:00:422 [sip] 00:48:24.420 pjcu.c [PJCU_ProcConnEvt():2758] case FSIP_CORE_REGISTER, PJCU_TASK_ID(0), eid(0) 15:53:00:425 [sip] 00:48:24.423 pjcu_entity.c [pjcu_getChanHandleByEid():363] Get channel id by endpoint id (0) fail 15:53:00:427 [sip] 00:48:24.425 pjcu.c [pjcu_config_acc():634] eid(0) is not mapping with pjcu accid, add a new account 15:53:00:432 [sip] 00:48:24.431 pjsua_acc.c Account "Test 3905 <>">@<>:5060> added with id 0 15:53:00:443 [sip] 00:48:24.442 sip_transport. Transport tcpc0x1928018 registered: type=TCP 15:53:00:445 [sip] 00:48:24.444 tcpc0x1928018 TCP client transport created 15:53:00:451 [sip] 00:48:24.446 tcpc0x1928018 TCP transport <>:4667 is connecting to <>:5060... 15:53:00:461 [sip] 00:48:24.457 pjsua_acc.c Registration sent 15:53:00:463 [sip] 00:48:24.461 pjcu.c [pjcu_config_acc():649] Add a new entity eid(0) mapping acc_id(0)("Test 3905 <>">@<>:5060>) 15:53:00:624 [sip] 00:48:24.623 tcpc0x1928018 TCP transport <>:4667 is connected to <>:5060 15:53:00:860 [sip] 00:48:24.856 pjsua_acc.c SIP outbound status for acc 0 is not active 15:53:00:863 [sip] 00:48:24.862 pjsua_acc.c "Test 3905 <>">@<>:5060>: registration success, status=200 (OK), will re-register in 120 seconds 15:53:00:870 [sip] 00:48:24.866 pjcu.c pjcu_on_reg_state2(), Account["Test 3905 <>">@<>:5060>] : OK, status=200 15:53:00:874 w [pcu] pcu_find_server_index(539) ipv4 format (<>)... 15:53:00:875 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:53:00:876 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_NORMAL_REG_OK, state=REGISTERING, server_index=0, active=999, standby=999, preferMode=1 15:53:00:880 w [pcu] [pcu_set_active_server_index] active_server_idx old=999, new=0 15:53:00:881 x [pcu] [pcu_msg_cc_insrv_cb():416]: regStatus=1, param2=<> 15:53:00:882 x [pcu] [pcux_insrv_cb():7412] CUCM_DateTime:Fri, 25 Aug 2023 05:53:01 GMT 15:53:00:883 x [pcu] Sync time from server: Fri, 25 Aug 2023 05:53:01 GMT 15:53:01:890 x [pcu] [set_svr_type][826] Bfe active_server_idx=0, serverType=0 15:53:01:891 x [pcu] [set_svr_type][829] Aft serverType=0, Server Number=2 15:53:01:892 x [pcu] [reset_polling_thread_cucm_flag():814] fallback_from_cm_to_cm = TRUE 15:53:01:893 x [pcu] [pcu_msg_cc_insrv_cb][503]REG ok, but need redoprovision 15:53:01:894 x [pcu] [pcux_2_pcu_notify_cb():916] pcux_2_pcu_notify_cb, cid=65535, e_NtyId=14 15:53:01:895 w [pcu] [normalRegOkHandler][2096]normalRegOkHandler, svr_idx=0, prefer=1, server_link_status=0 15:53:01:895 x [pcu] PCU state transit REGISTERING --> REGISTERED 15:53:01:896 x [pcu] pcu_send_keep_alive(511) index=1, isSrst=0, server_port=5060 15:53:01:900 w [pcu] [pcu_send_keep_alive][520] index=1, prefer=1, highPriority=0, polling_server_string=<>:5060;transport=tcp 15:53:01:903 [ipps] ----- PCU: CC_SRV, pid=0, eid=0, cid=65535 ----- 15:53:01:904 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 0 15:53:01:905 f [ipps] In func: remoteNtyEvtProcess(), recv inservice nty, svrType = 0, cause = 0 15:53:01:906 f [MMI] : In func: ui_nty(), lid = 0, cid = 65535, ntyEv = 0 15:53:01:910 x [CENTRAL] IPPS CB function(RegStatus) is called (1) with Line (0) 15:53:01:911 [ipps] In func: mlcu_isKpmlEnabled(), KPML value = 3, blRet = 1 15:53:01:912 [ipps] ----- PCU: CC_NTY, pid=0, eid=0, cid=65535 ----- 15:53:01:912 [ipps] In func: remoteNtyEvtProcess(), lid = 0, cid = 65535, ntyEv = 14 15:53:01:913 x [CENTRAL] IPPS CB function(Reprovisioning) is called 15:53:01:975 [sip] 00:48:24.974 pjcu.c pjcuRcvHandler(KA), KA_REQUEST, eid=-1, p1=<>:5060;transport=tcp 15:53:01:976 x [CENTRAL] Enter FSM: State(REGISTERING) | Event(REGISTER_OK) | Cause(0) 15:53:01:977 x [CENTRAL] State transit REGISTERING --> STANDBY 15:53:01:980 w [NTP] ntp_start() No NTP configed 15:53:01:981 x [CENTRAL] Waiting event in STANDBY 15:53:01:982 x [CENTRAL] Enter FSM: State(STANDBY) | Event(REPROVISION) | Cause(0) 15:53:01:982 x [CENTRAL] Start provision 15:53:01:983 x [CENTRAL] Waiting event in STANDBY 15:53:01:985 x [CENTRAL] Provision CB function is called (6) 15:53:01:986 x [CENTRAL] Enter FSM: State(STANDBY) | Event(PROV_CANCELED) | Cause(0) 15:53:01:986 x [CENTRAL] In func: eventHandler_suspendRet(), unexpected event PROV_CANCELED (cause=0) at STANDBY state 15:53:01:990 x [CENTRAL] Waiting event in STANDBY 15:53:02:102 w [PROVISION] provCfg_prepareTftpServer() selection group=(OPTION150, NONE) 15:53:02:206 [sip] 00:48:25.205 sip_transport. Transport tcpc0x1938018 registered: type=TCP 15:53:02:211 [sip] 00:48:25.210 tcpc0x1938018 TCP client transport created 15:53:02:214 [sip] 00:48:25.212 tcpc0x1938018 TCP transport <>:3269 is connecting to <>:5060... 15:53:02:265 [sip] 00:48:25.264 tcpc0x1938018 TCP transport <>:3269 is connected to <>:5060 15:53:02:320 w [SUU] tftp_cmd(GET), sessionId(0), rFilename(SEP08CC6830F94B.cnf.xml), dwServerIp(<>), dwPort(69), lPathFileName(/var/prov/SEP08CC6830F94B.cnf.xml), retryNum(6), maxFileSize(524288), tos(96) 15:53:02:380 [sip] 00:48:25.376 pjcu.c [pjcu_rpt_ka_status][774] target(<>:5060), status=1, id=2 15:53:02:384 w [pcu] pcu_find_server_index(539) ipv4 format (<>:5060)... 15:53:02:385 w [pcu] pcu_find_server_index(568) all_sip_server[0]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:53:02:386 w [pcu] pcu_find_server_index(568) all_sip_server[1]=<>:5060, server_ip=<>, server_ip_defer=, pureIp=<> 15:53:02:390 x [pcu] [pcu_reg_ka_msg_handle][1977]eid=0, evid=SIP_KEEP_ALIVE_OK, state=REGISTERED, server_index=1, active=0, standby=999, preferMode=1 15:53:02:391 w [pcu] [keepAliveOkHandler][2411]keepAliveOkHandler, svr_idx=1, prefer=1, server_link_status=2 15:53:02:392 w [pcu] [pcu_set_standby_server_index] standby_server_idx old=999, new=1 15:53:02:410 [sip] 00:48:25.406 tcpc0x1938018 TCP transport destroyed normally, remote:<>:5060