Troubles with codec negotiation
440 views
Skip to first unread message
Nikolai A. Dubinin
Aug 1, 2016, 9:49:27 AM8/1/16
to 2600hz-users
I am testing kazoo 4. I have built it from sources. Try to test make calls between various softphones. I have Bria for linux and Zoiper. If I call from Bria or to Bria, destination softphone is ringing. But if I answer to call, call is ends with incompatible_destination, codec negotiation error. I suppose, it grows from freeswitch build. I am using kamailio 4.4.2, freeswitch 1.6.9. Freeswitch built with additional
"amrwb" "ilbc" "isac" "mp4v" "siren" "theora" and default codecs. This trouble may be with sip-phones. Any ideas? Can I see spec files to build proper freeswitch and/or kamailio?
James Aimonetti
Aug 1, 2016, 10:12:40 AM8/1/16
to 2600hz...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
With Kazoo 4, we no longer package those projects and instead encourage
relying on the upstream versions.
You could post your SIP traces here and we could look at the SDP for the
two legs and spot something. But first, I would try the official
FreeSWITCH packages over the source builds; if the issue persists, look
at the negotiated codecs based on the SDP payloads for both legs.
- --
James Aimonetti
Lead Systems Architect
"If Dialyzer don't care, I don't care"
2600HzPDX | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
iQEcBAEBCAAGBQJXn1jSAAoJENTKa+JPXCVgYJ0H/jbZsI2W/8oT9Po4eagaCm32
dnTDeeuZLHSsVqHcJ3DYvt2bdMZuaTgATfiD7Ew/VXRsgQVHbRQ4XTRUjQHt9reQ
pypOPch+EyGHqjJTUfdutRHJjb6qYqqqXcKGzB2gp9sMRe7xHbOAA8ecB4CUagaK
mTC/kk0G6GICi9ZcTVjC/0RTX5rxLIvtLVU7/KoNnNeUr9rSzD8dNBQJavhMGww+
sCh2H3ZBzfNEgoEbT50dXrmm6FZt2LH4g56HvEXhswdEAEVnkh07jiC7a5U/QQta
vx7hNDnZks52a3jnMA8OGX8impjVHNBM39KsUH12ALPt0CVdSoR0Uc57OWgIXSY=
=N+on
-----END PGP SIGNATURE-----
Hash: SHA256
With Kazoo 4, we no longer package those projects and instead encourage
relying on the upstream versions.
You could post your SIP traces here and we could look at the SDP for the
two legs and spot something. But first, I would try the official
FreeSWITCH packages over the source builds; if the issue persists, look
at the negotiated codecs based on the SDP payloads for both legs.
James Aimonetti
Lead Systems Architect
"If Dialyzer don't care, I don't care"
2600HzPDX | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
iQEcBAEBCAAGBQJXn1jSAAoJENTKa+JPXCVgYJ0H/jbZsI2W/8oT9Po4eagaCm32
dnTDeeuZLHSsVqHcJ3DYvt2bdMZuaTgATfiD7Ew/VXRsgQVHbRQ4XTRUjQHt9reQ
pypOPch+EyGHqjJTUfdutRHJjb6qYqqqXcKGzB2gp9sMRe7xHbOAA8ecB4CUagaK
mTC/kk0G6GICi9ZcTVjC/0RTX5rxLIvtLVU7/KoNnNeUr9rSzD8dNBQJavhMGww+
sCh2H3ZBzfNEgoEbT50dXrmm6FZt2LH4g56HvEXhswdEAEVnkh07jiC7a5U/QQta
vx7hNDnZks52a3jnMA8OGX8impjVHNBM39KsUH12ALPt0CVdSoR0Uc57OWgIXSY=
=N+on
-----END PGP SIGNATURE-----
Nikolai A. Dubinin
Aug 2, 2016, 9:35:53 AM8/2/16
to 2600hz-users
I want to hear something, like voicemail greeting.
<pre> ------------------------------------------------------------------------
recv 1552 bytes from udp/[192.168.10.242]:5060 at 07:55:53.541825:
------------------------------------------------------------------------
INVITE sip:1...@k4.tel2kom.ru;transport=udp SIP/2.0
Record-Route: <sip:192.168.10.242;lr=on;ftag=0c724360>
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Max-Forwards: 50
Contact: <sip:1...@192.168.10.101:36352;transport=udp>
To: <sip:1...@k4.tel2kom.ru>
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
Supported: replaces
User-Agent: Bria 3 release 3.2 stamp 68886
Content-Length: 380
X-AUTH-IP: 192.168.10.101
X-AUTH-PORT: 36352
X-ecallmgr_Account-ID: 1d821776f1999ff7d10441fbf500fc00
X-ecallmgr_Authorizing-Type: device
X-ecallmgr_Authorizing-ID: 4213bd25730de2448a7808b5d3287cc6
X-ecallmgr_Username: 103
X-ecallmgr_Realm: k4.tel2kom.ru
X-ecallmgr_Account-Realm: k4.tel2kom.ru
X-ecallmgr_Account-Name: admin
X-ecallmgr_Presence-ID: 1...@k4.tel2kom.ru
X-ecallmgr_Owner-ID: 972340687863ade6553b26b8ec638b5f
v=0
o=- 1470124553489415 1 IN IP4 192.168.10.101
s=Counterpath Bria 3.1
c=IN IP4 192.168.10.101
t=0 0
a=ice-ufrag:03f775
a=ice-pwd:f199368cfb33749eaf517d40e76af3ed
m=audio 53376 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=candidate:1 1 UDP 659136 192.168.10.101 53376 typ host
a=candidate:1 2 UDP 659134 192.168.10.101 53377 typ host
------------------------------------------------------------------------
send 474 bytes to udp/[192.168.10.242]:5060 at 07:55:53.542188:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Record-Route: <sip:192.168.10.242;lr=on;ftag=0c724360>
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
To: <sip:1...@k4.tel2kom.ru>
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
User-Agent: 2600hz
Content-Length: 0
------------------------------------------------------------------------
2016-08-02 07:55:52.609935 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/1...@k4.tel2kom.ru [ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.]
2016-08-02 07:55:52.609935 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_NEW
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9456 sofia/sipinterface_1/1...@k4.tel2kom.ru receiving invite from 192.168.10.242:5060 version: 1.6.9 64bit
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9578 1 acls to check for proxy
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9583 checking 192.168.10.242 against acl authoritative
2016-08-02 07:55:52.609935 [INFO] sofia.c:9585 192.168.10.242 is a proxy according to the authoritative acl
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9595 network ip is a proxy
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9599 found auth ip [X-AUTH-IP] header of [192.168.10.101]
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9623 IP 192.168.10.242 Rejected by acl "trusted". Falling back to Digest auth.
2016-08-02 07:55:52.609935 [DEBUG] switch_xml.c:1988 Cache Info
Time Now: 1470124552609935
Expires: 1470066799482665
2016-08-02 07:55:52.609935 [DEBUG] switch_xml.c:1990 Cache expired for 1...@k4.tel2kom.ru, doing fresh lookup
2016-08-02 07:55:52.609935 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (4a0d48ef-a953-4522-adc2-92e6da39906c) to kazoo...@k1k4.tel2kom.ru <2.26497.49>
2016-08-02 07:55:52.649944 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.26497.49>
2016-08-02 07:55:52.669967 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (4a0d48ef-a953-4522-adc2-92e6da39906c) after 60ms: <document type="freeswitch/xml"><section name="directory"><domain name="k4.tel2kom.ru"><user id="103" cacheable="3600000"><variables><variable name="ecallmgr_Username" value="103"/><variable name="ecallmgr_Realm" value="k4.tel2kom.ru"/><variable name="ecallmgr_Account-ID" value="1d821776f1999ff7d10441fbf500fc00"/><variable name="ecallmgr_Authorizing-ID" value="4213bd25730de2448a7808b5d3287cc6"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Owner-ID" value="972340687863ade6553b26b8ec638b5f"/><variable name="ecallmgr_Account-Realm" value="k4.tel2kom.ru"/><variable name="ecallmgr_Account-Name" value="admin"/><variable name="presence_id" value="1...@k4.tel2kom.ru"/><variable name="ecallmgr_Suppress-Unregister-Notifications" value="true"/><variable name="ecallmgr_Register-Overwrite-Notify" value="false"/></variables><params><param name="password" value="123456"/></params></user></domain></section></document>
2016-08-02 07:55:52.669967 [DEBUG] switch_xml.c:2068 caching lookup for user 1...@k4.tel2kom.ru for 3600000 milliseconds
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:6933 Channel sofia/sipinterface_1/1...@k4.tel2kom.ru entering state [received][100]
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:6943 Remote SDP:
v=0
o=- 1470124553489415 1 IN IP4 192.168.10.101
s=Counterpath Bria 3.1
c=IN IP4 192.168.10.101
t=0 0
a=ice-ufrag:03f775
a=ice-pwd:f199368cfb33749eaf517d40e76af3ed
m=audio 53376 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=candidate:1 1 UDP 659136 192.168.10.101 53376 typ host
a=candidate:1 2 UDP 659134 192.168.10.101 53377 typ host
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:7305 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_NEW -> CS_INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:562 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State NEW
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:586 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State INIT
2016-08-02 07:55:52.669967 [DEBUG] mod_sofia.c:89 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_INIT -> CS_ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:586 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State INIT going to sleep
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_channel.c:2249 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Callstate Change DOWN -> RINGING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:602 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State ROUTING
2016-08-02 07:55:52.669967 [DEBUG] mod_sofia.c:142 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard ROUTING
2016-08-02 07:55:52.669967 [INFO] mod_dialplan_xml.c:637 Processing 103 <103>->102 in context context_2
2016-08-02 07:55:52.669967 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (172969a6-826c-4cdb-9ead-4f8d14e4e188) to kazoo...@k1k4.tel2kom.ru <2.26499.49>
2016-08-02 07:55:52.869955 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.26499.49>
2016-08-02 07:55:55.409958 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (172969a6-826c-4cdb-9ead-4f8d14e4e188) after 2739ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|kazoo...@k1k4.tel2kom.ru won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103"/><action application="multiunset" data="^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID"/><action application="park"/></condition></extension></context></section></document>
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru parsing [context_2->park] continue=false
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Absolute Condition [park]
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action log(NOTICE log|${uuid}|kazoo...@k1k4.tel2kom.ru won call control)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action export(ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action set(ringback=%(2000,4000,440,480))
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action set(transfer_ringback=%(2000,4000,440,480))
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action kz_multiset(^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action park()
|--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
|--- Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
|--- Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action export(ecallmgr_Bridge-ID=${UUID}) INLINE
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru export(ecallmgr_Bridge-ID=ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.)
2016-08-02 07:55:55.409958 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.]
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:286 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_ROUTING -> CS_EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:602 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State ROUTING going to sleep
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:609 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] mod_sofia.c:197 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard EXECUTE
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru log(NOTICE log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|kazoo...@k1k4.tel2kom.ru won call control)
2016-08-02 07:55:55.409958 [NOTICE] mod_dptools.c:1713 log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|kazoo...@k1k4.tel2kom.ru won call control
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru export(ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4120
2016-08-02 07:55:55.409958 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[kazoo...@k1k4.tel2kom.ru]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru set(ringback=%(2000,4000,440,480))
2016-08-02 07:55:55.409958 [DEBUG] mod_dptools.c:1519 SET sofia/sipinterface_1/1...@k4.tel2kom.ru [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru set(transfer_ringback=%(2000,4000,440,480))
2016-08-02 07:55:55.409958 [DEBUG] mod_dptools.c:1519 SET sofia/sipinterface_1/1...@k4.tel2kom.ru [transfer_ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru kz_multiset(^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Call-Interaction-ID]=[63637343753-bfe153ab]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Fetch-ID]=[172969a6-826c-4cdb-9ead-4f8d14e4e188]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Caller-Privacy-Number]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Caller-Privacy-Name]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-ID]=[1d821776f1999ff7d10441fbf500fc00]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-Name]=[admin]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-Realm]=[k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Authorizing-ID]=[4213bd25730de2448a7808b5d3287cc6]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Authorizing-Type]=[device]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Owner-ID]=[972340687863ade6553b26b8ec638b5f]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [presence_id]=[1...@k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Realm]=[k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Register-Overwrite-Notify]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Suppress-Unregister-Notifications]=[true]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Username]=[103]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4150
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru park()
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4159
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4134
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4115
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4150
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4120
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4159
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4134
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4115
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4106
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5253
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4106
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5253
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4825
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4825
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5515
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4878
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5515
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4202
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4878
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4202
2016-08-02 07:55:55.609959 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15619.57>
2016-08-02 07:55:55.609959 [INFO] kazoo_node.c:625 exec: kz_uuid_setvar_multi(ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU. ^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103;ecallmgr_Application-Node=kazoo...@k1k4.tel2kom.ru;ecallmgr_Application-Name=callflow)
2016-08-02 07:55:55.650050 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15619.57>
2016-08-02 07:55:55.650050 [INFO] kazoo_node.c:625 exec: kz_uuid_setvar_multi(ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU. ^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103;ecallmgr_Application-Node=kazoo...@k1k4.tel2kom.ru;ecallmgr_Application-Name=callflow;effective_caller_id_number=103;effective_caller_id_name=Nikolai Dubinin)
2016-08-02 07:55:55.849947 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15670.57>
2016-08-02 07:55:55.869937 [NOTICE] kazoo_node.c:285 log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|executing answer
2016-08-02 07:55:55.869937 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/1...@k4.tel2kom.ru Command Execute answer()
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru answer()
2016-08-02 07:55:55.869937 [DEBUG] mod_sofia.c:789 Disabling proxy mode due to call answer with no bridge
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3091 Set Codec sofia/sipinterface_1/1...@k4.tel2kom.ru PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2016-08-02 07:55:55.869937 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/1...@k4.tel2kom.ru Original read codec set to PCMA:8
2016-08-02 07:55:55.869937 [WARNING] switch_core_media.c:3465 NO candidate ACL defined, Defaulting to wan.auto
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3495 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.10.101:53376
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3495 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.10.101:53377
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:4634 Set telephone-event payload to 101@8000
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:4693 sofia/sipinterface_1/1...@k4.tel2kom.ru Set 2833 dtmf send payload to 101 recv payload to 101
2016-08-02 07:55:55.889937 [NOTICE] switch_channel.c:3809 Hangup sofia/sipinterface_1/1...@k4.tel2kom.ru [CS_EXECUTE] [INCOMPATIBLE_DESTINATION]
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:2797 sofia/sipinterface_1/1...@k4.tel2kom.ru skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:2797 sofia/sipinterface_1/1...@k4.tel2kom.ru skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:609 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State EXECUTE going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_HANGUP
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:809 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Callstate Change RINGING -> HANGUP
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:811 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State HANGUP
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:437 Channel sofia/sipinterface_1/1...@k4.tel2kom.ru hanging up, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:576 Responding to INVITE with: 488
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:811 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State HANGUP going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:578 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_HANGUP -> CS_REPORTING
send 940 bytes to udp/[192.168.10.242]:5060 at 07:55:56.813538:
------------------------------------------------------------------------
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Max-Forwards: 50
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
To: <sip:1...@k4.tel2kom.ru>;tag=gUjQ0FKy25c9Q
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
User-Agent: 2600hz
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Reason: Q.850;cause=88;text="INCOMPATIBLE_DESTINATION"
Content-Length: 0
Remote-Party-ID: "102" <sip:1...@k4.tel2kom.ru>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_REPORTING
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:897 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State REPORTING
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:897 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State REPORTING going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_REPORTING -> CS_DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:1647 Session 44 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Locked, Waiting on external entities
2016-08-02 07:55:55.889937 [NOTICE] switch_core_session.c:1665 Session 44 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Ended
2016-08-02 07:55:55.889937 [NOTICE] switch_core_session.c:1669 Close Channel sofia/sipinterface_1/1...@k4.tel2kom.ru [CS_DESTROY]
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:700 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:710 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State DESTROY
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:342 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:710 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State DESTROY going to sleep
2016-08-02 07:55:55.889937 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4105
2016-08-02 07:55:55.889937 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4105
recv 334 bytes from udp/[192.168.10.242]:5060 at 07:55:56.815515:
------------------------------------------------------------------------
ACK sip:1...@k4.tel2kom.ru;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Max-Forwards: 50
To: <sip:1...@k4.tel2kom.ru>;tag=gUjQ0FKy25c9Q
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 ACK
Content-Length: 0
</pre>
<pre> ------------------------------------------------------------------------
recv 1552 bytes from udp/[192.168.10.242]:5060 at 07:55:53.541825:
------------------------------------------------------------------------
INVITE sip:1...@k4.tel2kom.ru;transport=udp SIP/2.0
Record-Route: <sip:192.168.10.242;lr=on;ftag=0c724360>
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Max-Forwards: 50
Contact: <sip:1...@192.168.10.101:36352;transport=udp>
To: <sip:1...@k4.tel2kom.ru>
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
Supported: replaces
User-Agent: Bria 3 release 3.2 stamp 68886
Content-Length: 380
X-AUTH-IP: 192.168.10.101
X-AUTH-PORT: 36352
X-ecallmgr_Account-ID: 1d821776f1999ff7d10441fbf500fc00
X-ecallmgr_Authorizing-Type: device
X-ecallmgr_Authorizing-ID: 4213bd25730de2448a7808b5d3287cc6
X-ecallmgr_Username: 103
X-ecallmgr_Realm: k4.tel2kom.ru
X-ecallmgr_Account-Realm: k4.tel2kom.ru
X-ecallmgr_Account-Name: admin
X-ecallmgr_Presence-ID: 1...@k4.tel2kom.ru
X-ecallmgr_Owner-ID: 972340687863ade6553b26b8ec638b5f
v=0
o=- 1470124553489415 1 IN IP4 192.168.10.101
s=Counterpath Bria 3.1
c=IN IP4 192.168.10.101
t=0 0
a=ice-ufrag:03f775
a=ice-pwd:f199368cfb33749eaf517d40e76af3ed
m=audio 53376 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=candidate:1 1 UDP 659136 192.168.10.101 53376 typ host
a=candidate:1 2 UDP 659134 192.168.10.101 53377 typ host
------------------------------------------------------------------------
send 474 bytes to udp/[192.168.10.242]:5060 at 07:55:53.542188:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Record-Route: <sip:192.168.10.242;lr=on;ftag=0c724360>
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
To: <sip:1...@k4.tel2kom.ru>
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
User-Agent: 2600hz
Content-Length: 0
------------------------------------------------------------------------
2016-08-02 07:55:52.609935 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/1...@k4.tel2kom.ru [ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.]
2016-08-02 07:55:52.609935 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_NEW
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9456 sofia/sipinterface_1/1...@k4.tel2kom.ru receiving invite from 192.168.10.242:5060 version: 1.6.9 64bit
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9578 1 acls to check for proxy
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9583 checking 192.168.10.242 against acl authoritative
2016-08-02 07:55:52.609935 [INFO] sofia.c:9585 192.168.10.242 is a proxy according to the authoritative acl
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9595 network ip is a proxy
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9599 found auth ip [X-AUTH-IP] header of [192.168.10.101]
2016-08-02 07:55:52.609935 [DEBUG] sofia.c:9623 IP 192.168.10.242 Rejected by acl "trusted". Falling back to Digest auth.
2016-08-02 07:55:52.609935 [DEBUG] switch_xml.c:1988 Cache Info
Time Now: 1470124552609935
Expires: 1470066799482665
2016-08-02 07:55:52.609935 [DEBUG] switch_xml.c:1990 Cache expired for 1...@k4.tel2kom.ru, doing fresh lookup
2016-08-02 07:55:52.609935 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (4a0d48ef-a953-4522-adc2-92e6da39906c) to kazoo...@k1k4.tel2kom.ru <2.26497.49>
2016-08-02 07:55:52.649944 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.26497.49>
2016-08-02 07:55:52.669967 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (4a0d48ef-a953-4522-adc2-92e6da39906c) after 60ms: <document type="freeswitch/xml"><section name="directory"><domain name="k4.tel2kom.ru"><user id="103" cacheable="3600000"><variables><variable name="ecallmgr_Username" value="103"/><variable name="ecallmgr_Realm" value="k4.tel2kom.ru"/><variable name="ecallmgr_Account-ID" value="1d821776f1999ff7d10441fbf500fc00"/><variable name="ecallmgr_Authorizing-ID" value="4213bd25730de2448a7808b5d3287cc6"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Owner-ID" value="972340687863ade6553b26b8ec638b5f"/><variable name="ecallmgr_Account-Realm" value="k4.tel2kom.ru"/><variable name="ecallmgr_Account-Name" value="admin"/><variable name="presence_id" value="1...@k4.tel2kom.ru"/><variable name="ecallmgr_Suppress-Unregister-Notifications" value="true"/><variable name="ecallmgr_Register-Overwrite-Notify" value="false"/></variables><params><param name="password" value="123456"/></params></user></domain></section></document>
2016-08-02 07:55:52.669967 [DEBUG] switch_xml.c:2068 caching lookup for user 1...@k4.tel2kom.ru for 3600000 milliseconds
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:6933 Channel sofia/sipinterface_1/1...@k4.tel2kom.ru entering state [received][100]
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:6943 Remote SDP:
v=0
o=- 1470124553489415 1 IN IP4 192.168.10.101
s=Counterpath Bria 3.1
c=IN IP4 192.168.10.101
t=0 0
a=ice-ufrag:03f775
a=ice-pwd:f199368cfb33749eaf517d40e76af3ed
m=audio 53376 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=candidate:1 1 UDP 659136 192.168.10.101 53376 typ host
a=candidate:1 2 UDP 659134 192.168.10.101 53377 typ host
2016-08-02 07:55:52.669967 [DEBUG] sofia.c:7305 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_NEW -> CS_INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:562 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State NEW
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:586 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State INIT
2016-08-02 07:55:52.669967 [DEBUG] mod_sofia.c:89 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard INIT
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_INIT -> CS_ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:586 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State INIT going to sleep
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_channel.c:2249 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Callstate Change DOWN -> RINGING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:602 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State ROUTING
2016-08-02 07:55:52.669967 [DEBUG] mod_sofia.c:142 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA ROUTING
2016-08-02 07:55:52.669967 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard ROUTING
2016-08-02 07:55:52.669967 [INFO] mod_dialplan_xml.c:637 Processing 103 <103>->102 in context context_2
2016-08-02 07:55:52.669967 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (172969a6-826c-4cdb-9ead-4f8d14e4e188) to kazoo...@k1k4.tel2kom.ru <2.26499.49>
2016-08-02 07:55:52.869955 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.26499.49>
2016-08-02 07:55:55.409958 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (172969a6-826c-4cdb-9ead-4f8d14e4e188) after 2739ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|kazoo...@k1k4.tel2kom.ru won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103"/><action application="multiunset" data="^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID"/><action application="park"/></condition></extension></context></section></document>
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru parsing [context_2->park] continue=false
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Absolute Condition [park]
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action log(NOTICE log|${uuid}|kazoo...@k1k4.tel2kom.ru won call control)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action export(ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action set(ringback=%(2000,4000,440,480))
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action set(transfer_ringback=%(2000,4000,440,480))
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action kz_multiset(^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action park()
|--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
|--- Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
|--- Dialplan: sofia/sipinterface_1/1...@k4.tel2kom.ru Action export(ecallmgr_Bridge-ID=${UUID}) INLINE
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru export(ecallmgr_Bridge-ID=ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.)
2016-08-02 07:55:55.409958 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.]
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:286 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_ROUTING -> CS_EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:602 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State ROUTING going to sleep
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:609 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] mod_sofia.c:197 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA EXECUTE
2016-08-02 07:55:55.409958 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard EXECUTE
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru log(NOTICE log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|kazoo...@k1k4.tel2kom.ru won call control)
2016-08-02 07:55:55.409958 [NOTICE] mod_dptools.c:1713 log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|kazoo...@k1k4.tel2kom.ru won call control
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru export(ecallmgr_Ecallmgr-Node=kazoo...@k1k4.tel2kom.ru)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4120
2016-08-02 07:55:55.409958 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[kazoo...@k1k4.tel2kom.ru]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru set(ringback=%(2000,4000,440,480))
2016-08-02 07:55:55.409958 [DEBUG] mod_dptools.c:1519 SET sofia/sipinterface_1/1...@k4.tel2kom.ru [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru set(transfer_ringback=%(2000,4000,440,480))
2016-08-02 07:55:55.409958 [DEBUG] mod_dptools.c:1519 SET sofia/sipinterface_1/1...@k4.tel2kom.ru [transfer_ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru kz_multiset(^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Call-Interaction-ID]=[63637343753-bfe153ab]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Fetch-ID]=[172969a6-826c-4cdb-9ead-4f8d14e4e188]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Caller-Privacy-Number]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Caller-Privacy-Name]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-ID]=[1d821776f1999ff7d10441fbf500fc00]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-Name]=[admin]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Account-Realm]=[k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Authorizing-ID]=[4213bd25730de2448a7808b5d3287cc6]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Authorizing-Type]=[device]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Owner-ID]=[972340687863ade6553b26b8ec638b5f]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [presence_id]=[1...@k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Realm]=[k4.tel2kom.ru]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Register-Overwrite-Notify]=[false]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Suppress-Unregister-Notifications]=[true]
2016-08-02 07:55:55.409958 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/1...@k4.tel2kom.ru SET [ecallmgr_Username]=[103]
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4150
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru park()
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4159
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4134
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4115
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4150
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4120
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4159
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4134
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4115
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4106
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5253
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4106
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5253
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4825
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4825
2016-08-02 07:55:55.409958 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5515
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4878
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5515
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4202
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4878
2016-08-02 07:55:55.429944 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4202
2016-08-02 07:55:55.609959 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15619.57>
2016-08-02 07:55:55.609959 [INFO] kazoo_node.c:625 exec: kz_uuid_setvar_multi(ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU. ^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103;ecallmgr_Application-Node=kazoo...@k1k4.tel2kom.ru;ecallmgr_Application-Name=callflow)
2016-08-02 07:55:55.650050 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15619.57>
2016-08-02 07:55:55.650050 [INFO] kazoo_node.c:625 exec: kz_uuid_setvar_multi(ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU. ^^;ecallmgr_Call-Interaction-ID=63637343753-bfe153ab;ecallmgr_Fetch-ID=172969a6-826c-4cdb-9ead-4f8d14e4e188;ecallmgr_Caller-Privacy-Number=false;ecallmgr_Caller-Privacy-Name=false;ecallmgr_Account-ID=1d821776f1999ff7d10441fbf500fc00;ecallmgr_Account-Name=admin;ecallmgr_Account-Realm=k4.tel2kom.ru;ecallmgr_Authorizing-ID=4213bd25730de2448a7808b5d3287cc6;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=972340687863ade6553b26b8ec638b5f;presence_id=1...@k4.tel2kom.ru;ecallmgr_Realm=k4.tel2kom.ru;ecallmgr_Register-Overwrite-Notify=false;ecallmgr_Suppress-Unregister-Notifications=true;ecallmgr_Username=103;ecallmgr_Application-Node=kazoo...@k1k4.tel2kom.ru;ecallmgr_Application-Name=callflow;effective_caller_id_number=103;effective_caller_id_name=Nikolai Dubinin)
2016-08-02 07:55:55.849947 [DEBUG] kazoo_node.c:1100 Sent erlang message to kazoo...@k1k4.tel2kom.ru <2.15670.57>
2016-08-02 07:55:55.869937 [NOTICE] kazoo_node.c:285 log|ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.|executing answer
2016-08-02 07:55:55.869937 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/1...@k4.tel2kom.ru Command Execute answer()
EXECUTE sofia/sipinterface_1/1...@k4.tel2kom.ru answer()
2016-08-02 07:55:55.869937 [DEBUG] mod_sofia.c:789 Disabling proxy mode due to call answer with no bridge
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4420 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4365 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:4281 Set telephone-event payload to 101@8000
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3091 Set Codec sofia/sipinterface_1/1...@k4.tel2kom.ru PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2016-08-02 07:55:55.869937 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/1...@k4.tel2kom.ru Original read codec set to PCMA:8
2016-08-02 07:55:55.869937 [WARNING] switch_core_media.c:3465 NO candidate ACL defined, Defaulting to wan.auto
2016-08-02 07:55:55.869937 [DEBUG] switch_core_media.c:3495 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.10.101:53376
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3495 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.10.101:53377
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3537 Searching for rtp candidate.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3537 Searching for rtcp candidate.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:3581 sofia/sipinterface_1/1...@k4.tel2kom.ru no suitable candidates found.
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:4634 Set telephone-event payload to 101@8000
2016-08-02 07:55:55.889937 [DEBUG] switch_core_media.c:4693 sofia/sipinterface_1/1...@k4.tel2kom.ru Set 2833 dtmf send payload to 101 recv payload to 101
2016-08-02 07:55:55.889937 [NOTICE] switch_channel.c:3809 Hangup sofia/sipinterface_1/1...@k4.tel2kom.ru [CS_EXECUTE] [INCOMPATIBLE_DESTINATION]
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:2797 sofia/sipinterface_1/1...@k4.tel2kom.ru skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:2797 sofia/sipinterface_1/1...@k4.tel2kom.ru skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:609 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State EXECUTE going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_HANGUP
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:809 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Callstate Change RINGING -> HANGUP
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:811 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State HANGUP
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:437 Channel sofia/sipinterface_1/1...@k4.tel2kom.ru hanging up, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:576 Responding to INVITE with: 488
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:811 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State HANGUP going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:578 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_HANGUP -> CS_REPORTING
send 940 bytes to udp/[192.168.10.242]:5060 at 07:55:56.813538:
------------------------------------------------------------------------
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Via: SIP/2.0/UDP 192.168.10.101:36352;received=192.168.10.101;branch=z9hG4bK-d8754z-478f2226e06e1304-1---d8754z-;rport=36352
Max-Forwards: 50
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
To: <sip:1...@k4.tel2kom.ru>;tag=gUjQ0FKy25c9Q
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 INVITE
User-Agent: 2600hz
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Reason: Q.850;cause=88;text="INCOMPATIBLE_DESTINATION"
Content-Length: 0
Remote-Party-ID: "102" <sip:1...@k4.tel2kom.ru>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:543 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_REPORTING
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:897 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State REPORTING
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:897 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State REPORTING going to sleep
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State Change CS_REPORTING -> CS_DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_session.c:1647 Session 44 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Locked, Waiting on external entities
2016-08-02 07:55:55.889937 [NOTICE] switch_core_session.c:1665 Session 44 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Ended
2016-08-02 07:55:55.889937 [NOTICE] switch_core_session.c:1669 Close Channel sofia/sipinterface_1/1...@k4.tel2kom.ru [CS_DESTROY]
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:700 (sofia/sipinterface_1/1...@k4.tel2kom.ru) Running State Change CS_DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:710 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State DESTROY
2016-08-02 07:55:55.889937 [DEBUG] mod_sofia.c:342 sofia/sipinterface_1/1...@k4.tel2kom.ru SOFIA DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/1...@k4.tel2kom.ru Standard DESTROY
2016-08-02 07:55:55.889937 [DEBUG] switch_core_state_machine.c:710 (sofia/sipinterface_1/1...@k4.tel2kom.ru) State DESTROY going to sleep
2016-08-02 07:55:55.889937 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4105
2016-08-02 07:55:55.889937 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4105
recv 334 bytes from udp/[192.168.10.242]:5060 at 07:55:56.815515:
------------------------------------------------------------------------
ACK sip:1...@k4.tel2kom.ru;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.10.242;branch=z9hG4bKbebb.d8ca077a712d7171d9d6a44d29e962c3.0
Max-Forwards: 50
To: <sip:1...@k4.tel2kom.ru>;tag=gUjQ0FKy25c9Q
From: <sip:1...@k4.tel2kom.ru>;tag=0c724360
Call-ID: ZGI1NzhkMTk4NDIxYzJlNTY1NzdkODY3NTA1NWE3MGU.
CSeq: 1 ACK
Content-Length: 0
</pre>
Nikolai A. Dubinin
Aug 3, 2016, 10:28:40 AM8/3/16
to 2600hz-users
Trouble solved with freeswitch 1.6.8 install.
Reply all
Reply to author
Forward
0 new messages