О деактивации форума Eltex

Уважаемые коллеги! В связи с потерей актуальности данного ресурса, нами было принято решение о частичной деактивации форума Eltex. Мы отключили функции регистрации и создания новых тем, а также возможность оставлять сообщения. Форум продолжит работу в "режиме чтения", так как за долгие годы работы здесь накопилось много полезной информации и ответов на часто встречающиеся вопросы.

Мы активно развиваем другие каналы коммуникаций, которые позволяют более оперативно и адресно консультировать наших клиентов. Если у вас возникли вопросы по работе оборудования, вы можете обратиться в техническую поддержку Eltex, воспользовавшись формой обращения на сайте компании или оставить заявку в системе Service Desk. По иным вопросам проконсультируют наши менеджеры коммерческого отдела: eltex@eltex-co.ru.

TAU-8IP бросает трубку через 30 секунд

ECSS-10, TAU.IP, SMG, RG
Leonel
Сообщения: 1
Зарегистрирован: 02 сен 2022 20:26
Reputation: 0

TAU-8IP бросает трубку через 30 секунд

Сообщение Leonel » 02 сен 2022 20:41

Добрый день! Внутренние звонки проходят нормально, извне - 30 секунд и отбой.
Версия ПО: #2.6.7-b7-ru
Где копать?

Код: Выделить всё

Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]slic5. Event 2.
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]slic 5. Off-hook event
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Set port 5 led to state 'LED_ON'
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]HIO: offhook TDM port '5' port enabled 1
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]SLIC 5 (phone150): offhook state: ringing
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]regex ID 5: dial reset
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]SLIC 5: -> talking(call id: 02050000)
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]pbx -[msg_answer]-> sip
Sep  2 16:34:37 TAU-8 user.info syslog: 16:34:37.536[app:info]SLIC 5: from state 'ringing' to state 'talking'
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]CMD_STOP_TONE: port = 5
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:1516, function vapi_stop_tone_chan()]
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Chan 5: current state is CREATED
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Port 5: set vapi queue MSP to 'busy' with 'stop_tone' at [vapi_chan.c:1562, function vapi_stop_tone_chan()]
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]VQ Conn 5 = MSP :     'stop_tone' =
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]chan 5 stop tone
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Port 5: user port 3, old state talking, new state
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]pbx -[msg_fxs_state]-> group
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]dump_port_calls() SLIC 5:
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Q:(0x33ec00,0x02050000,(nil))
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]... preparing to read from pipe
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]Unmute all RX-TX medias on SLIC 5
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]ITC: [msg_answer] -> sip
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sip: call 02050000: endpoint 5 answered
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sip: call 02050000: INVITE: 200 OK SIP_T NO
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sip: call 02050000: set endpoint 5
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]self_on_answer() sdp state <receive> - create answer sdp
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() ssup absent on, ecan absent on, rfc present 101, nse absent 0, ptime present 20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G723: none
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G711A:
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() PT 8, vbd absent off
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G711U:
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() PT 0, vbd absent off
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G726-24: none
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G726-32: none
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() G722:
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_dump() PT 9
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_g711a_add_to_media_attrs() g711a: have one at last
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_g711u_add_to_media_attrs() g711u: have one at last
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_rfc2833_add_to_media_attrs() present, pt 101
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_nse_add_to_media_attrs() absent, pt 0
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_ptime_add_to_attrs() ptime present 20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_ecan_add_to_attrs() ecan absent on
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_ssup_add_to_attrs() ssup absent on
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_tail:  8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]make_sdp: SDP: s=Session SDP m=audio 12004 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_set_ptime() ptime present : 20
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.536[app:dbg]sdp_codecs_get_rfc2833: present=1 pt=101
Sep  2 16:34:37 TAU-8 user.warn syslog: 16:34:37.536[app:WARN][get_group_profile_id]-1 is not group index!!!!
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x00000924
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]ITC: [msg_fxs_state] -> group
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]-----[GM] self_fxs_state()
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]Port 5: new state is talking
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x00000924 result 0x00000000
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]Conn 5: Stop tone - Successfull
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]Port 5: check vapi queue ('busy''stop_tone') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:34:37 TAU-8 user.debug syslog: 16:34:37.546[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 5
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]send 1138 bytes to tcp/[95.213.198.99]:5060 at 09:41:46.880000:    ------------------------------------------------------------------------
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   SIP/2.0 200 OK
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   Via: SIP/2.0/TCP 95.213.198.99:5060;rport=5060;branch=z9hG4bKPj9f0985c76251bcafc5f5e57f11bac479;alias
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   v: SIP/2.0/TCP 185.164.149.20:44009;rport=44009;received=185.164.149.20;branch=z9hG4bKPjc1D-Ou4T7pfaAgclXLAjKMQIaxFjUndK;alias
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   Record-Route: <sip:95.213.198.99:5060;transport=TCP;lr>
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   f: <sip:79818915737@ip.b24-9983-1528359928.bitrixphone.com>;tag=VVVVV185.164.149.20_5090_1ad68efe740ec4fd80ba0c2d46c3f86c
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   To: <sip:phone150@ip.b24-9983-1528359928.bitrixphone.com>;tag=evS8yZ6DS4QHN
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   i: 1dc54YnUPB33m0BVtv6A8aATi0UR-0P0
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   CSeq: 1559 INVITE
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   Contact: <sip:phone150@192.168.5.227:5060>
Sep  2 16:34:37 TAU-8 user.notice syslog: 16:34:37.586[sip]   User-Agent: TAU-8.IP/2.6.7 SN/VI33028492 sofia-sip/1.9

Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Supported: timer, 100rel, replaces
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Min-SE: 120
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Content-Type: application/sdp
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Content-Disposition: session
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   Content-Length: 210
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   v=0
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   s=Session SDP
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   c=IN IP4 192.168.5.227
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   t=0 0
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   a=fmtp:101 0-15
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   a=ptime:20
Sep  2 16:34:45 TAU-8 user.notice syslog: 16:34:45.126[sip]   ------------------------------------------------------------------------
Sep  2 16:34:45 TAU-8 user.debug syslog: 16:34:45.436[app:dbg]... preparing to read from pipe
Sep  2 16:34:45 TAU-8 user.warn syslog: 16:34:45.436[app:WARN]__REPEAT
Sep  2 16:34:46 TAU-8 user.debug syslog: 16:34:46.516[app:dbg]... preparing to read from pipe
Sep  2 16:34:46 TAU-8 user.warn syslog: 16:34:46.516[app:WARN]__REPEAT
Sep  2 16:34:47 TAU-8 user.debug syslog: 16:34:47.596[app:dbg]... preparing to read from pipe
Sep  2 16:34:47 TAU-8 user.warn syslog: 16:34:47.596[app:WARN]__REPEAT
Sep  2 16:34:48 TAU-8 user.debug syslog: 16:34:48.676[app:dbg]... preparing to read from pipe
Sep  2 16:34:48 TAU-8 user.warn syslog: 16:34:48.676[app:WARN]__REPEAT
Sep  2 16:34:49 TAU-8 user.notice syslog: 16:34:49.136[sip]send 1138 bytes to tcp/[95.213.198.99]:5060 at 09:41:58.430000:    ------------------------------------------------------------------------

Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Supported: timer, 100rel, replaces
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Min-SE: 120
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Content-Type: application/sdp
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Content-Disposition: session
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   Content-Length: 210
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   v=0
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   s=Session SDP
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   c=IN IP4 192.168.5.227
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   t=0 0
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   a=fmtp:101 0-15
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   a=ptime:20
Sep  2 16:34:53 TAU-8 user.notice syslog: 16:34:53.146[sip]   ------------------------------------------------------------------------
Sep  2 16:34:54 TAU-8 user.debug syslog: 16:34:54.076[app:dbg]... preparing to read from pipe
Sep  2 16:34:54 TAU-8 user.warn syslog: 16:34:54.076[app:WARN]__REPEAT
Sep  2 16:34:55 TAU-8 user.debug syslog: 16:34:55.156[app:dbg]... preparing to read from pipe
Sep  2 16:34:55 TAU-8 user.warn syslog: 16:34:55.156[app:WARN]__REPEAT
Sep  2 16:34:56 TAU-8 user.debug syslog: 16:34:56.236[app:dbg]... preparing to read from pipe
Sep  2 16:34:56 TAU-8 user.warn syslog: 16:34:56.236[app:WARN]__REPEAT
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]send 855 bytes to tcp/[95.213.198.99]:5060 at 09:42:06.200000:    ------------------------------------------------------------------------

Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   Supported: timer, 100rel, replaces, path
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   Proxy-Authorization: Digest username="phone150", realm="voximplant.com", nonce="5aeece906add8f89", opaque="3a2f23083c083e0e", algorithm=MD5, uri="sip:
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   ip.b24-9983-1528359928.bitrixphone.com", response="7ce9fd14d2bfa42e7fa2920280929564"
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   Content-Length: 0
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   
Sep  2 16:34:56 TAU-8 user.notice syslog: 16:34:56.906[sip]   ------------------------------------------------------------------------
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]send 1138 bytes to tcp/[95.213.198.99]:5060 at 09:42:06.450000:    ---------------------------
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Supported: timer, 100rel, replaces
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Min-SE: 120
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Content-Type: application/sdp
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Content-Disposition: session
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   Content-Length: 210
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   v=0
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   s=Session SDP
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   c=IN IP4 192.168.5.227
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   t=0 0
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   a=fmtp:101 0-15
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   a=ptime:20
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.156[sip]   ------------------------------------------------------------------------
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]recv 398 bytes from tcp/[95.213.198.99]:5060 at 09:42:06.560000:    ------------------------------------------------------------------------
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   SIP/2.0 200 OK
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   v: SIP/2.0/TCP 192.168.5.227;rport=50825;received=95.161.222.61;branch=z9hG4bK5rSQpBUaFc3gp
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   i: 106400dd-a565-123b-ddb9-a8f94b15f392
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   f: <sip:phone150@ip.b24-9983-1528359928.bitrixphone.com>;tag=41vgDHyapBSpH
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   t: <sip:phone150@ip.b24-9983-1528359928.bitrixphone.com>;tag=z9hG4bK5rSQpBUaFc3gp
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   CSeq: 36 REGISTER
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   m: <sip:phone150@10.25.158.2:5060>;expires=130
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   Expires: 130
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   l: 0
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   
Sep  2 16:34:57 TAU-8 user.notice syslog: 16:34:57.266[sip]   ------------------------------------------------------------------------
Sep  2 16:34:57 TAU-8 user.debug syslog: 16:34:57.266[app:dbg]got nua_r_register : 200(OK)
Sep  2 16:34:57 TAU-8 user.debug syslog: 16:34:57.266[app:dbg]sip: endpoint 5: REGISTER: 200 OK
Sep  2 16:34:57 TAU-8 user.debug syslog: 16:34:57.266[app:dbg]Port 5: user port 3, old state talking, new state
Sep  2 16:34:57 TAU-8 user.debug syslog: 16:34:57.266[app:dbg]sip: endpoint 5: successfully registered
Sep  2 16:34:57 TAU-8 user.debug syslog: 16:34:57.316[app:dbg]... preparing to read from pipe
Sep  2 16:34:57 TAU-8 user.warn syslog: 16:34:57.316[app:WARN]__REPEAT
Sep  2 16:34:58 TAU-8 user.debug syslog: 16:34:58.396[app:dbg]... preparing to read from pipe
Sep  2 16:34:58 TAU-8 user.warn syslog: 16:34:58.396[app:WARN]__REPEAT
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]send 847 bytes to tcp/[95.213.198.99]:5060 at 09:42:08.220000:    ------------------------------------------------------------------------

Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   Supported: timer, 100rel, replaces, path
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   Proxy-Authorization: Digest username="phone1", realm="voximplant.com", nonce="38223714003926da", opaque="051509a338cef4f2", algorithm=MD5, uri="sip:ip
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   .b24-9983-1528359928.bitrixphone.com", response="3393613b048384274b5b66633502ba95"
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   Content-Length: 0
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   
Sep  2 16:34:58 TAU-8 user.notice syslog: 16:34:58.926[sip]   ------------------------------------------------------------------------
Sep  2 16:34:59 TAU-8 user.notice syslog: 16:34:59.266[sip]recv 392 bytes from tcp/[95.213.198.99]:5060 at 09:42:08.560000:    --------------------------
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Supported: timer, 100rel, replaces
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Min-SE: 120
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Content-Type: application/sdp
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Content-Disposition: session
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   Content-Length: 210
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   v=0
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   s=Session SDP
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   c=IN IP4 192.168.5.227
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   t=0 0
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   a=fmtp:101 0-15
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   a=ptime:20
Sep  2 16:35:01 TAU-8 user.notice syslog: 16:35:01.166[sip]   ------------------------------------------------------------------------
Sep  2 16:35:01 TAU-8 user.debug syslog: 16:35:01.636[app:dbg]... preparing to read from pipe
Sep  2 16:35:01 TAU-8 user.warn syslog: 16:35:01.636[app:WARN]__REPEAT
Sep  2 16:35:02 TAU-8 user.debug syslog: 16:35:02.716[app:dbg]... preparing to read from pipe
Sep  2 16:35:02 TAU-8 user.warn syslog: 16:35:02.716[app:WARN]__REPEAT
Sep  2 16:35:03 TAU-8 user.debug syslog: 16:35:03.796[app:dbg]... preparing to read from pipe
Sep  2 16:35:03 TAU-8 user.warn syslog: 16:35:03.796[app:WARN]__REPEAT
Sep  2 16:35:04 TAU-8 user.debug syslog: 16:35:04.876[app:dbg]... preparing to read from pipe
Sep  2 16:35:04 TAU-8 user.warn syslog: 16:35:04.876[app:WARN]__REPEAT
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]send 1138 bytes to tcp/[95.213.198.99]:5060 at 09:42:14.470000:    ------------------------------------------------------------------------

Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Supported: timer, 100rel, replaces
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Min-SE: 120
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Content-Type: application/sdp
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Content-Disposition: session
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   Content-Length: 210
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   v=0
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   s=Session SDP
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   c=IN IP4 192.168.5.227
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   t=0 0
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   a=fmtp:101 0-15
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   a=ptime:20
Sep  2 16:35:05 TAU-8 user.notice syslog: 16:35:05.176[sip]   ------------------------------------------------------------------------
Sep  2 16:35:05 TAU-8 user.debug syslog: 16:35:05.956[app:dbg]... preparing to read from pipe
Sep  2 16:35:05 TAU-8 user.warn syslog: 16:35:05.956[app:WARN]__REPEAT
Sep  2 16:35:07 TAU-8 user.debug syslog: 16:35:07.036[app:dbg]... preparing to read from pipe
Sep  2 16:35:07 TAU-8 user.warn syslog: 16:35:07.036[app:WARN]__REPEAT
Sep  2 16:35:08 TAU-8 user.debug syslog: 16:35:08.116[app:dbg]... preparing to read from pipe
Sep  2 16:35:08 TAU-8 user.warn syslog: 16:35:08.116[app:WARN]__REPEAT
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]send 1138 bytes to tcp/[95.213.198.99]:5060 at 09:42:18.480000:    ---------------------------
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Supported: timer, 100rel, replaces
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Session-Expires: 1800;refresher=uas
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Min-SE: 120
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Content-Type: application/sdp
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Content-Disposition: session
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   Content-Length: 210
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   v=0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   o=- 6718197144190623291 2316302827016473515 IN IP4 192.168.5.227
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   s=Session SDP
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   c=IN IP4 192.168.5.227
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   t=0 0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   m=audio 12004 RTP/AVP 8 101
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   a=rtpmap:101 telephone-event/8000
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   a=fmtp:101 0-15
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   a=ptime:20
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.186[sip]   ------------------------------------------------------------------------
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.196[app:dbg]... preparing to read from pipe
Sep  2 16:35:09 TAU-8 user.warn syslog: 16:35:09.196[app:WARN]__REPEAT
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.596[app:dbg]got nua_i_error : 408(ACK Timeout)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.596[app:dbg]NO SIP IN nua_i_error == 408 : ACK Timeout
Sep  2 16:35:09 TAU-8 user.err syslog: 16:35:09.596[app:ERR]sip: sip library error nua_i_error (0), status: 408 ACK Timeout!
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]send 737 bytes to tcp/[95.213.198.99]:5060 at 09:42:18.890000:    ------------------------------------------------------------------------
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   BYE sip:185.164.149.20:5090;transport=tcp SIP/2.0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Via: SIP/2.0/TCP 192.168.5.227;branch=z9hG4bK7ac9S1vH9XFpD
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Route: <sip:95.213.198.99:5060;transport=TCP;lr>
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Max-Forwards: 70
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   From: <sip:phone150@ip.b24-9983-1528359928.bitrixphone.com>;tag=evS8yZ6DS4QHN
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   To: <sip:79818915737@ip.b24-9983-1528359928.bitrixphone.com>;tag=VVVVV185.164.149.20_5090_1ad68efe740ec4fd80ba0c2d46c3f86c
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Call-ID: 1dc54YnUPB33m0BVtv6A8aATi0UR-0P0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   CSeq: 421 BYE
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Contact: <sip:phone150@192.168.5.227:5060>
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   User-Agent: TAU-8.IP/2.6.7 SN/VI33028492 sofia-sip/1.9
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Supported: timer, 100rel, replaces
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Reason: SIP;cause=408;text="ACK Timeout"
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   Content-Length: 0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.596[sip]   ------------------------------------------------------------------------
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.596[app:dbg]got nua_i_state : 0(ACK Timeout)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.596[app:dbg]NO SIP IN nua_i_state == 0 : ACK Timeout
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.596[app:dbg]self_i_state(): call state 9: : : sdp_init have_oc
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]recv 416 bytes from tcp/[95.213.198.99]:5060 at 09:42:18.930000:    ------------------------------------------------------------------------
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   SIP/2.0 200 OK
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   v: SIP/2.0/TCP 192.168.5.227;rport=50825;received=95.161.222.61;branch=z9hG4bK7ac9S1vH9XFpD
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   i: 1dc54YnUPB33m0BVtv6A8aATi0UR-0P0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   f: <sip:phone150@ip.b24-9983-1528359928.bitrixphone.com>;tag=evS8yZ6DS4QHN
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   t: <sip:79818915737@ip.b24-9983-1528359928.bitrixphone.com>;tag=VVVVV185.164.149.20_5090_1ad68efe740ec4fd80ba0c2d46c3f86c
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   CSeq: 421 BYE
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   User-Agent: VIMS
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   m: <sip:185.164.149.20:5090>
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   l: 0
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.636[sip]   
Sep  2 16:35:09 TAU-8 user.notice syslog: 16:35:09.646[sip]   ------------------------------------------------------------------------
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]got nua_r_bye : 200(OK)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]sip: call 02050000: BYE/INFO: 200 OK
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]got nua_i_state : 200(to BYE)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]NO SIP IN nua_i_state == 200 : to BYE
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]self_i_state(): call state 10: : : sdp_init have_oc
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]sip: call 02050000: terminated
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]8186: endpoint 5 set to ready
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]sip -[msg_clear]-> pbx
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]self_callstate_terminated: call id = 02050000 need_exchange_at_answer = 0
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]ITC: [msg_clear] -> pbx
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]dump_port_calls() SLIC 5:
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Q:(0x33ec00,0x02050000,(nil))
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: peer cleared(02050000)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: current call cleared
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: -> busy - no hold call, no wait call
Sep  2 16:35:09 TAU-8 user.info syslog: 16:35:09.646[app:info]SLIC 5: from state 'talking' to state 'busy'
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]port_start_tone(5 22 0 0)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]CMD_START_TONE: port = 5
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:1425, function vapi_start_tone_chan()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Chan 5: current state is CREATED
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Port 5: set vapi queue MSP to 'busy' with 'start_tone' at [vapi_chan.c:1462, function vapi_start_tone_chan()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]VQ Conn 5 = MSP :    'start_tone' =
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Conn 5, tone config: tone_high: 425Hz, tone_low: 0Hz, tone_t_on1: 330ms, tone_t_off1: 330ms, tone_t_on2: 0ms, tone_t_off2: 0ms
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]chan 5 start tone, id=22, direction=TDM
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Port 5: user port 3, old state busy, new state
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]pbx -[msg_fxs_state]-> group
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: connection STATISTIC
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: Rx_pack = 1519
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: Rx_oct  = 261268
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: Lost_pack  = 0
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: Tx_pack = 1341
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: Tx_oct  = 218727
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]vapi: chan 5: peak_jiter = 11
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Common port statistic
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Rx_pack = 1519
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Rx_oct  = 261268
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Lost_pack  = 0
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Tx_pack = 1341
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: Tx_oct  = 218727
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: peak_jiter = 11
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]SLIC 5: reset call 0x02050000 (active)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]CMD_SET_VOICE: port = 5
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Port 5: check vapi queue ('busy''start_tone') at [vapi_chan.c:1665, function vapi_start_stop_chan()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.646[app:dbg]Port 5 put cmd 'set voice',cur 'start_tone' to queue at (vapi_start_stop_chan:1672)
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]VQ Conn 5 = MSP :    'start_tone' =
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]VQ Conn 5 + 00  :     'set voice'  + <-get_ptr
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]incom_calls_set_media_started() call 0x02050000, group -1, task <sip> media stopped
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]incom_calls_rem() rem call 0x02050000, group -1, task <sip> from list
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]... preparing to read from pipe
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]Delete all RX-TX medias from SLIC 5
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]dump_port_calls() SLIC 5:
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]Q:NONE
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]received signal or msg for updating stats
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x00000923
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.656[app:dbg]ITC: [msg_fxs_state] -> group
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]-----[GM] self_fxs_state()
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Port 5: new state is busy
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x00000923 result 0x00000000
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Conn 5: Start tone - Successfull
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Port 5: check vapi queue ('busy''start_tone') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Port 5 get cmd 'set voice' from queue at [vapi_chan.c:2631, function vapi_next_ops()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:1665, function vapi_start_stop_chan()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Chan 5: current state is CREATED
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]vapi: Conn 5. start_stop voice chan, TX stop, RX stop
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]Port 5: set vapi queue MSP to 'busy' with 'set voice' at [vapi_chan.c:1708, function vapi_start_stop_chan()]
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.666[app:dbg]VQ Conn 5 = MSP :     'set voice' =
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x00000401
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x00000401 result 0x00000000
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi: conn 5. RTCP disabled
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x000004ff
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x000004ff result 0x00000000
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]Conn 5: Set voice mode successeful
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]Stop all medias on chan 5
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]... preparing to read from pipe
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]Mute all RX-TX medias on SLIC 5
Sep  2 16:35:09 TAU-8 user.debug syslog: 16:35:09.676[app:dbg]Port 5: check vapi queue ('busy''set voice') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]send 851 bytes to tcp/[95.213.198.99]:5060 at 09:42:19.330000:    ------------------------------------------------------------------------
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   REGISTER sip:ip.b24-9983-1528359928.bitrixphone.com SIP/2.0
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Via: SIP/2.0/TCP 192.168.5.227;branch=z9hG4bK8K51UvDN6658r
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Max-Forwards: 70
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   From: <sip:phone14@ip.b24-9983-1528359928.bitrixphone.com>;tag=6KF2g7ZHgX5Ur
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   To: <sip:phone14@ip.b24-9983-1528359928.bitrixphone.com>
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Call-ID: 10fe1dfd-a565-123b-dfb9-a8f94b15f392
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   CSeq: 36 REGISTER
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Contact: <sip:phone14@192.168.5.227:5060>
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Expires: 1800
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   User-Agent: TAU-8.IP/2.6.7 SN/VI33028492 sofia-sip/1.9
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Supported: timer, 100rel, replaces, path
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Proxy-Authorization: Digest username="phone14", realm="voximplant.com", nonce="0f18ef2f2cc80865", opaque="474de71e451d7a85", algorithm=MD5, uri="sip:i
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   p.b24-9983-1528359928.bitrixphone.com", response="cd751bc5fac57994f046a4afec56397e"
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   Content-Length: 0
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.036[sip]   ------------------------------------------------------------------------
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]recv 395 bytes from tcp/[95.213.198.99]:5060 at 09:42:19.620000:    ------------------------------------------------------------------------
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   SIP/2.0 200 OK
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   v: SIP/2.0/TCP 192.168.5.227;rport=50825;received=95.161.222.61;branch=z9hG4bK8K51UvDN6658r
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   i: 10fe1dfd-a565-123b-dfb9-a8f94b15f392
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   f: <sip:phone14@ip.b24-9983-1528359928.bitrixphone.com>;tag=6KF2g7ZHgX5Ur
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   t: <sip:phone14@ip.b24-9983-1528359928.bitrixphone.com>;tag=z9hG4bK8K51UvDN6658r
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   CSeq: 36 REGISTER
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   m: <sip:phone14@10.25.158.2:5060>;expires=130
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   Expires: 130
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   l: 0
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   
Sep  2 16:35:10 TAU-8 user.notice syslog: 16:35:10.326[sip]   ------------------------------------------------------------------------
Sep  2 16:35:10 TAU-8 user.debug syslog: 16:35:10.326[app:dbg]got nua_r_register : 200(OK)
Sep  2 16:35:10 TAU-8 user.debug syslog: 16:35:10.326[app:dbg]sip: endpoint 7: REGISTER: 200 OK
Sep  2 16:35:10 TAU-8 user.debug syslog: 16:35:10.326[app:dbg]Port 7: user port 1, old state hangup, new state
Sep  2 16:35:10 TAU-8 user.debug syslog: 16:35:10.326[app:dbg]sip: endpoint 7: successfully registered
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]send 851 bytes to tcp/[95.213.198.99]:5060 at 09:42:22.360000:    ------------------------------------------------------------------------
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   REGISTER sip:ip.b24-9983-1528359928.bitrixphone.com SIP/2.0
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Via: SIP/2.0/TCP 192.168.5.227;branch=z9hG4bK9vytXQyr3FvUm
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Max-Forwards: 70
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   From: <sip:phone42@ip.b24-9983-1528359928.bitrixphone.com>;tag=3r3QBpD7r223N
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   To: <sip:phone42@ip.b24-9983-1528359928.bitrixphone.com>
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Call-ID: 1017b59d-a565-123b-dcb9-a8f94b15f392
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   CSeq: 35 REGISTER
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Contact: <sip:phone42@192.168.5.227:5060>
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Expires: 1800
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   User-Agent: TAU-8.IP/2.6.7 SN/VI33028492 sofia-sip/1.9
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Supported: timer, 100rel, replaces, path
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Proxy-Authorization: Digest username="phone42", realm="voximplant.com", nonce="50a28b1677966a00", opaque="2f22cbb126347281", algorithm=MD5, uri="sip:i
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   p.b24-9983-1528359928.bitrixphone.com", response="d7fe15cbabf877e8c6f467de2c76575a"
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   Content-Length: 0
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.066[sip]   ------------------------------------------------------------------------
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]recv 395 bytes from tcp/[95.213.198.99]:5060 at 09:42:22.640000:    ------------------------------------------------------------------------
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   SIP/2.0 200 OK
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   v: SIP/2.0/TCP 192.168.5.227;rport=50825;received=95.161.222.61;branch=z9hG4bK9vytXQyr3FvUm
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   i: 1017b59d-a565-123b-dcb9-a8f94b15f392
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   f: <sip:phone42@ip.b24-9983-1528359928.bitrixphone.com>;tag=3r3QBpD7r223N
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   t: <sip:phone42@ip.b24-9983-1528359928.bitrixphone.com>;tag=z9hG4bK9vytXQyr3FvUm
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   CSeq: 35 REGISTER
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   m: <sip:phone42@10.25.158.2:5060>;expires=130
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   Expires: 130
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   l: 0
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   
Sep  2 16:35:13 TAU-8 user.notice syslog: 16:35:13.346[sip]   ------------------------------------------------------------------------
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.346[app:dbg]got nua_r_register : 200(OK)
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.346[app:dbg]sip: endpoint 4: REGISTER: 200 OK
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.346[app:dbg]Port 4: user port 2, old state hangup, new state
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.346[app:dbg]sip: endpoint 4: successfully registered
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.606[app:dbg]slic5. Event 8.
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.606[app:dbg]slic 5. Pre-On-hook event
Sep  2 16:35:13 TAU-8 user.debug syslog: 16:35:13.606[app:dbg]HIO: preonhook TDM port '5', port enabled 1
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]slic5. Event 1.
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]slic 5. On-hook event
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Set port 5 led to state 'LED_OFF'
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]HIO: onhook TDM port '5', port enabled 1
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]SLIC 5 (phone150): onhook state: busy
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]regex ID 5: dial reset
Sep  2 16:35:14 TAU-8 user.info syslog: 16:35:14.116[app:info]SLIC 5: from state 'busy' to state 'hangup'
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]CMD_STOP_TONE: port = 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:1516, function vapi_stop_tone_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Chan 5: current state is CREATED
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: set vapi queue MSP to 'busy' with 'stop_tone' at [vapi_chan.c:1562, function vapi_stop_tone_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 = MSP :     'stop_tone' =
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]chan 5 stop tone
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]SLIC 5: reset
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]dump_port_calls() SLIC 5:
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Q:NONE
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]free_final_mx: final_mx was NULL for SLIC 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]CMD_DESTROY_CONN: port = 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: check vapi queue ('busy''stop_tone') at [vapi_chan.c:904, function vapi_destroy_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg][vapi_chan.c:906] vapi_destroy_chan(): Clear vapi queue of Port 5/chan 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5 put cmd 'destroy',cur 'stop_tone' to queue at (vapi_destroy_chan:911)
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 = MSP :     'stop_tone' =
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 + 00  :       'destroy'  + <-get_ptr
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]CMD_DESTROY_IPONLY_CONN: port = 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: check vapi queue ('busy''stop_tone') at [vapi_chan.c:904, function vapi_destroy_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg][vapi_chan.c:906] vapi_destroy_chan(): Clear vapi queue of Port 5/chan 13
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5 put cmd 'destroy',cur 'stop_tone' to queue at (vapi_destroy_chan:911)
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 13 = MSP :     'stop_tone' =
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 13 + 00  :       'destroy'  + <-get_ptr
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 13 + 01  :       'destroy' (hold) + 
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: user port 3, old state hangup, new state
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]pbx -[msg_fxs_state]-> group
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]dump_port_calls() SLIC 5:
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Q:NONE
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]H:((nil),0x00000000,(nil),0) W:((nil),0x00000000,(nil)) N:((nil),0x00000000,(nil)) H2:((nil),0x00000000,(nil))
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Set port 5 led to state 'LED_OFF'
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]... preparing to read from pipe
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Delete all RX-TX medias from SLIC 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x00000924
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]ITC: [msg_fxs_state] -> group
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]-----[GM] self_fxs_state()
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: new state is hangup
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x00000924 result 0x00000000
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Conn 5: Stop tone - Successfull
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: check vapi queue ('busy''stop_tone') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5 get cmd 'destroy' from queue at [vapi_chan.c:2631, function vapi_next_ops()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 + 01  :       'destroy' (hold) + <-get_ptr
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:904, function vapi_destroy_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Destroying connection 5...
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Chan 5: current state is CREATED
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Port 5: set vapi queue MSP to 'busy' with 'destroy' at [vapi_chan.c:930, function vapi_destroy_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 = MSP :       'destroy' =
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]VQ Conn 5 + 01  :       'destroy' (hold) + <-get_ptr
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.116[app:dbg]Chan 5: CREATED -> DESTROYING
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]... preparing to read from pipe
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]Delete all RX-TX medias from SLIC 13
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x0000014c
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x0000014c result 0x00000000
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.126[app:dbg]vapi: generic event, code 2 <Tone Generation completed>, conn 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]... preparing to read from pipe
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Delete all RX-TX medias from SLIC 5
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]vapi_cb_req: 5 0 result 0x00000000 requid 0x00000103
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]vapi_proc_event: VAPI_CB
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]vapi_cb_chan: chan 5 reqest_id 0x00000103 result 0x00000000
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Conn 5 destroyed
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Chan 5: DESTROYING -> INITIAL
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Port 5: check vapi queue ('busy''destroy') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Port 5 get cmd 'destroy' from queue at [vapi_chan.c:2631, function vapi_next_ops()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:904, function vapi_destroy_chan()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Destroying connection 13...
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Chan 13: current state is INITIAL
Sep  2 16:35:14 TAU-8 user.err syslog: 16:35:14.136[app:ERR]vapi_destroy_chan() chan 13: current state initial: duplicate destroying connection!
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:2774, function vapi_next_ops()]
Sep  2 16:35:14 TAU-8 user.debug syslog: 16:35:14.136[app:dbg]Port 5: check vapi queue ('free') at [vapi_chan.c:2612, function vapi_next_ops()]
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]send 851 bytes to tcp/[95.213.198.99]:5060 at 09:43:17.910000:    ------------------------------------------------------------------------
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   REGISTER sip:ip.b24-9983-1528359928.bitrixphone.com SIP/2.0
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Via: SIP/2.0/TCP 192.168.5.227;branch=z9hG4bKa6QKZjFv0rjeg
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Max-Forwards: 70
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   From: <sip:phone40@ip.b24-9983-1528359928.bitrixphone.com>;tag=5ap9ecFeKmF9c
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   To: <sip:phone40@ip.b24-9983-1528359928.bitrixphone.com>
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Call-ID: 10b1d2bd-a565-123b-deb9-a8f94b15f392
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   CSeq: 37 REGISTER
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Contact: <sip:phone40@192.168.5.227:5060>
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Expires: 1800
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   User-Agent: TAU-8.IP/2.6.7 SN/VI33028492 sofia-sip/1.9
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Supported: timer, 100rel, replaces, path
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Proxy-Authorization: Digest username="phone40", realm="voximplant.com", nonce="5d453f2d1a41016d", opaque="5182789635749e85", algorithm=MD5, uri="sip:i
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   p.b24-9983-1528359928.bitrixphone.com", response="0ebade5b975b80d070f06e856335ae2d"
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   Content-Length: 0
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.616[sip]   ------------------------------------------------------------------------
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]recv 395 bytes from tcp/[95.213.198.99]:5060 at 09:43:18.190000:    ------------------------------------------------------------------------
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   SIP/2.0 200 OK
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   v: SIP/2.0/TCP 192.168.5.227;rport=50825;received=95.161.222.61;branch=z9hG4bKa6QKZjFv0rjeg
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   i: 10b1d2bd-a565-123b-deb9-a8f94b15f392
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   f: <sip:phone40@ip.b24-9983-1528359928.bitrixphone.com>;tag=5ap9ecFeKmF9c
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   t: <sip:phone40@ip.b24-9983-1528359928.bitrixphone.com>;tag=z9hG4bKa6QKZjFv0rjeg
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   CSeq: 37 REGISTER
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   m: <sip:phone40@10.25.158.2:5060>;expires=129
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   Expires: 129
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   l: 0
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   
Sep  2 16:36:08 TAU-8 user.notice syslog: 16:36:08.896[sip]   ------------------------------------------------------------------------
Sep  2 16:36:08 TAU-8 user.debug syslog: 16:36:08.896[app:dbg]got nua_r_register : 200(OK)
Sep  2 16:36:08 TAU-8 user.debug syslog: 16:36:08.896[app:dbg]sip: endpoint 6: REGISTER: 200 OK
Sep  2 16:36:08 TAU-8 user.debug syslog: 16:36:08.896[app:dbg]Port 6: user port 0, old state hangup, new state
Sep  2 16:36:08 TAU-8 user.debug syslog: 16:36:08.896[app:dbg]sip: endpoint 6: successfully registered

Dmitriy_eltex
Сообщения: 1234
Зарегистрирован: 28 окт 2014 08:53
Reputation: 10

Re: TAU-8IP бросает трубку через 30 секунд

Сообщение Dmitriy_eltex » 05 сен 2022 09:21

Здравствуйте.

Судя по логу, TAU8 шлет 200 ОК, но провайдер не отвечает на него ACK.
Вызов отбивается по таймауту, т.к. не было получено подтверждение.
Возможно, провайдет не знает куда отправить ACK, т.к. получает серый IP адрес в 200ОК.
Судя по всему, Ваша TAU8 стоит за NAT, следовательно нужно включить STUN, либо публичный адрес прописать:
https://docs.eltex-co.ru/pages/viewpage ... d=45453408

PS: светить IP адреса на форуме - плохая примета.
Дмитрий Закурдаев / Элтекс / Сервисный центр VoIP


Вернуться в «Оборудование VoIP»

Кто сейчас на конференции

Сейчас этот форум просматривают: нет зарегистрированных пользователей и 19 гостей