[Freeswitch-users] trans-coding is not working
thomas peterseil
thomas.peterseil at gmail.com
Thu Jan 30 20:02:50 MSK 2014
hello,
here are the logs from the cli with sip trace on with this problem:
--------------------
freeswitch at internal>
recv 2305 bytes from udp/[192.168.5.10]:20842 at 16:53:06.430550:
------------------------------------------------------------------------
PUBLISH sip:1000 at 192.168.65.98 SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPj18e288b0ce3340a59a0ce2d3134fe4c5
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272
To: "thomas" <sip:1000 at 192.168.65.98>
Call-ID: 08af2532df5f4c058b66de677cb88f3a
CSeq: 1 PUBLISH
Event: presence
Expires: 600
SIP-If-Match: FBwNeu9F
User-Agent: Blink 0.6.0 (Windows)
Content-Type: application/pidf+xml
Content-Length: 1825
<?xml version='1.0' encoding='UTF-8'?>
<presence xmlns:c="urn:ietf:params:xml:ns:pidf:cipid"
xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model"
xmlns:agp-caps="urn:ag-projects:xml:ns:pidf:caps"
xmlns:caps="urn:ietf:params:xml:ns:pidf:caps"
xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid"
xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf"
xmlns="urn:ietf:params:xml:ns:pidf"
entity="sip%3A1000%40192.168.65.98"><tuple
id="SID-ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><status><basic>open</basic><agp-pidf:extended>busy</agp-pidf:extended></status><caps:servcaps><caps:audio>true</caps:audio><caps:message>false</caps:message><caps:text>false</caps:text><agp-caps:file-transfer>false</agp-caps:file-transfer><agp-caps:screen-sharing-server>false</agp-caps:screen-sharing-server><agp-caps:screen-sharing-client>false</agp-caps:screen-sharing-client></caps:servcaps><c:display-name>thomas</c:display-name><agp-pidf:device-info
id="ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><agp-pidf:description>OPTI-10</agp-pidf:description><agp-pidf:user-agent>:user-agent><agp-pidf:time-offset>60</agp-pidf:time-offset></agp-pidf:device-info><rpid:user-input
idle-threshold="600">active</rpid:user-input><dm:deviceID>ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99</dm:deviceID><contact>sip%3A1000%40192.168.65.98</contact><note>On
the phone</note><timestamp>2014-01-30T17:53:03.589000+01:00</timestamp></tuple><dm:person
id="PID-3dadb95a5ce54f457c35c3c2a9ddf52a"><rpid:activities><rpid:busy/></rpid:activities><dm:timestamp>2014-01-30T17:53:03.589000+01:00</dm:timestamp></dm:person><dm:device
id="DID-ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><dm:deviceID>ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99</dm:deviceID><dm:note>Blink
0.6.0 (Windows) at
OPTI-10</dm:note><dm:timestamp>2014-01-30T17:53:03.589000+01:00</dm:timestamp></dm:device></presence>
------------------------------------------------------------------------
send 778 bytes to udp/[192.168.5.10]:20842 at 16:53:06.432299:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPj18e288b0ce3340a59a0ce2d3134fe4c5;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272
To: "thomas" <sip:1000 at 192.168.65.98>;tag=2p634jB77Byac
Call-ID: 08af2532df5f4c058b66de677cb88f3a
CSeq: 1 PUBLISH
Contact: <sip:192.168.65.98>
Expires: 600
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize,
call-info, sla, include-session-description, presence.winfo,
message-summary, refer
SIP-ETag: yTJwnz2d
Content-Length: 0
------------------------------------------------------------------------
recv 828 bytes from udp/[192.168.5.10]:20842 at 16:53:06.446771:
------------------------------------------------------------------------
INVITE sip:1001 at 192.168.65.98 SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>
Contact: <sip:49583627 at 192.168.129.229:2425>
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22405 INVITE
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE,
MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
User-Agent: Blink 0.6.0 (Windows)
Content-Type: application/sdp
Content-Length: 239
v=0
o=- 3600093183 3600093183 IN IP4 192.168.129.229
s=Blink 0.6.0 (Windows)
c=IN IP4 192.168.129.229
t=0 0
m=audio 50040 RTP/AVP 8 96
a=rtcp:50041
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
------------------------------------------------------------------------
send 383 bytes to udp/[192.168.5.10]:20842 at 16:53:06.447052:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22405 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:06.442538 [NOTICE] switch_channel.c:1052 New Channel
sofia/internal/1000 at 192.168.65.98
[505cd4ee-eb6f-4b1b-91e5-2988258e9410]
2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.442538 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_NEW
2014-01-30 17:53:06.442538 [DEBUG] sofia.c:7834
sofia/internal/1000 at 192.168.65.98 receiving invite from
192.168.5.10:20842 version: 1.2.18 -1 64bit
2014-01-30 17:53:06.442538 [DEBUG] sofia.c:7985 IP 192.168.5.10
Rejected by acl "domains". Falling back to Digest auth.
send 883 bytes to udp/[192.168.5.10]:20842 at 16:53:06.447832:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=3ZZv6Dva5mmXQ
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22405 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize,
call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Proxy-Authenticate: Digest realm="192.168.65.98",
nonce="6e75dcd4-79e3-4562-97a4-c88fc292cd6f", algorithm=MD5,
qop="auth"
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.442538 [DEBUG] sofia.c:1794 detaching session
505cd4ee-eb6f-4b1b-91e5-2988258e9410
2014-01-30 17:53:06.442538 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/1000 at 192.168.65.98) State NEW
recv 391 bytes from udp/[192.168.5.10]:20842 at 16:53:06.452970:
------------------------------------------------------------------------
ACK sip:1001 at 192.168.65.98 SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=3ZZv6Dva5mmXQ
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22405 ACK
User-Agent: Blink 0.6.0 (Windows)
Content-Length: 0
------------------------------------------------------------------------
recv 1098 bytes from udp/[192.168.5.10]:20842 at 16:53:06.475581:
------------------------------------------------------------------------
INVITE sip:1001 at 192.168.65.98 SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>
Contact: <sip:49583627 at 192.168.129.229:2425>
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22406 INVITE
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE,
MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
User-Agent: Blink 0.6.0 (Windows)
Proxy-Authorization: Digest username="1000", realm="192.168.65.98",
nonce="6e75dcd4-79e3-4562-97a4-c88fc292cd6f",
uri="sip:1001 at 192.168.65.98",
response="c388584cea57037857fa19d191927a33", algorithm=MD5,
cnonce="4bffd2f3ec9944cf806aae69bb6d87e6", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length: 239
v=0
o=- 3600093183 3600093183 IN IP4 192.168.129.229
s=Blink 0.6.0 (Windows)
c=IN IP4 192.168.129.229
t=0 0
m=audio 50040 RTP/AVP 8 96
a=rtcp:50041
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
------------------------------------------------------------------------
send 383 bytes to udp/[192.168.5.10]:20842 at 16:53:06.475828:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22406 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:06.463222 [DEBUG] sofia.c:1886 Re-attaching to
session 505cd4ee-eb6f-4b1b-91e5-2988258e9410
2014-01-30 17:53:06.463222 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.463222 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:7834
sofia/internal/1000 at 192.168.65.98 receiving invite from
192.168.5.10:20842 version: 1.2.18 -1 64bit
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:7985 IP 192.168.5.10
Rejected by acl "domains". Falling back to Digest auth.
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:5779 Channel
sofia/internal/1000 at 192.168.65.98 entering state [received][100]
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:5792 Remote SDP:
v=0
o=- 3600093183 3600093183 IN IP4 192.168.129.229
s=Blink 0.6.0 (Windows)
c=IN IP4 192.168.129.229
t=0 0
m=audio 50040 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=rtcp:50041
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:6039
(sofia/internal/1000 at 192.168.65.98) State Change CS_NEW -> CS_INIT
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_INIT
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/1000 at 192.168.65.98) State INIT
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87
sofia/internal/1000 at 192.168.65.98 SOFIA INIT
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127
(sofia/internal/1000 at 192.168.65.98) State Change CS_INIT -> CS_ROUTING
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/1000 at 192.168.65.98) State INIT going to sleep
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_ROUTING
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:2165
(sofia/internal/1000 at 192.168.65.98) Callstate Change DOWN -> RINGING
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/1000 at 192.168.65.98) State ROUTING
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:150
sofia/internal/1000 at 192.168.65.98 SOFIA ROUTING
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:117
sofia/internal/1000 at 192.168.65.98 Standard ROUTING
2014-01-30 17:53:06.482481 [INFO] mod_dialplan_xml.c:558 Processing
thomas <1000>->1001 in context default
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing [default->unloop]
continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->tod_example] continue=true
Dialplan: sofia/internal/1000 at 192.168.65.98 Date/Time Match (PASS)
[tod_example] break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(open=true)
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/1000 at 192.168.65.98 Date/TimeMatch (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[global-intercept] destination_number(1001) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing [default->redial]
continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [redial]
destination_number(1001) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing [default->global]
continue=true
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [global]
${sip_has_crypto}() =~
/^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (PASS) [global]
${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED
NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [global]
${switch_r_sdp}(v=0
o=- 3600093183 3600093183 IN IP4 192.168.129.229
s=Blink 0.6.0 (Windows)
c=IN IP4 192.168.129.229
t=0 0
m=audio 50040 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=rtcp:50041
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1000 at 192.168.65.98 Absolute Condition [global]
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->snom-demo-2] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [snom-demo-2]
destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [snom-demo-1]
destination_number(1001) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->call_return] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [call_return]
destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->del-group] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [del-group]
destination_number(1001) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->add-group] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [add-group]
destination_number(1001) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[call-group-simo] destination_number(1001) =~ /^82(\d{2})$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[call-group-order] destination_number(1001) =~ /^83(\d{2})$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
[extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (PASS)
[Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1000 at 192.168.65.98 Action export(dialed_extension=1001)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(2 b s
record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(ringback=${us-ring})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(call_timeout=30)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(continue_on_fail=true)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1000 at 192.168.65.98 Action answer()
Dialplan: sofia/internal/1000 at 192.168.65.98 Action sleep(1000)
Dialplan: sofia/internal/1000 at 192.168.65.98 Action
bridge(loopback/app=voicemail:default ${domain_name}
${dialed_extension})
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/1000 at 192.168.65.98) State Change CS_ROUTING ->
CS_EXECUTE
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/1000 at 192.168.65.98) State ROUTING going to sleep
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_EXECUTE
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:478
(sofia/internal/1000 at 192.168.65.98) State EXECUTE
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:243
sofia/internal/1000 at 192.168.65.98 SOFIA EXECUTE
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:209
sofia/internal/1000 at 192.168.65.98 Standard EXECUTE
EXECUTE sofia/internal/1000 at 192.168.65.98 set(open=true)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET [open]=[true]
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-spymap/1000/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial/1000/1001)
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98 export(RFC2822_DATE=Thu, 30
Jan 2014 17:53:06 +0100)
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1244 EXPORT
(export_vars) [RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100]
EXECUTE sofia/internal/1000 at 192.168.65.98 export(dialed_extension=1001)
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1244 EXPORT
(export_vars) [dialed_extension]=[1001]
EXECUTE sofia/internal/1000 at 192.168.65.98 bind_meta_app(1 b s
execute_extension::dx XML features)
2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*1 execute_extension::dx XML features
EXECUTE sofia/internal/1000 at 192.168.65.98 bind_meta_app(2 b s
record_session::/var/lib/freeswitch/recordings/1000.2014-01-30-17-53-06.wav)
2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*2 record_session::/var/lib/freeswitch/recordings/1000.2014-01-30-17-53-06.wav
EXECUTE sofia/internal/1000 at 192.168.65.98 bind_meta_app(3 b s
execute_extension::cf XML features)
2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*3 execute_extension::cf XML features
EXECUTE sofia/internal/1000 at 192.168.65.98 bind_meta_app(4 b s
execute_extension::att_xfer XML features)
2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg:
*4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/1000 at 192.168.65.98 set(ringback=%(2000,4000,440,480))
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET
[ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1000 at 192.168.65.98
set(transfer_ringback=local_stream://moh)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1000 at 192.168.65.98 set(call_timeout=30)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET [call_timeout]=[30]
EXECUTE sofia/internal/1000 at 192.168.65.98 set(hangup_after_bridge=true)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1000 at 192.168.65.98 set(continue_on_fail=true)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-call_return/1001/1000)
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial_ext/1001/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98
set(called_party_callgroup=techsupport)
2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
sofia/internal/1000 at 192.168.65.98 SET
[called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial_ext/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial_ext/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98
hash(insert/192.168.65.98-last_dial/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
EXECUTE sofia/internal/1000 at 192.168.65.98 bridge(user/1001 at 192.168.65.98)
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2014-01-30 17:53:06.482481 [DEBUG] switch_ivr_originate.c:2061 Parsing
global variables
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event
2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2014-01-30 17:53:06.482481 [DEBUG] switch_ivr_originate.c:2061 Parsing
global variables
2014-01-30 17:53:06.482481 [DEBUG] switch_event.c:1661 Parsing
variable [sip_invite_domain]=[192.168.65.98]
2014-01-30 17:53:06.482481 [DEBUG] switch_event.c:1661 Parsing
variable [presence_id]=[1001 at 192.168.65.98]
2014-01-30 17:53:06.482481 [NOTICE] switch_channel.c:1052 New Channel
sofia/internal/sip:1001 at 192.168.65.124:3588
[cab230d1-27d2-443c-b531-81dac71c027c]
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5231
(sofia/internal/sip:1001 at 192.168.65.124:3588) State Change CS_NEW ->
CS_INIT
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5301 [zrtp_passthru]
Setting a-leg inherit_codec=true
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5304 [zrtp_passthru]
Setting b-leg absolute_codec_string='PCMA at 8000h@20i at 64000b'
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_INIT
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:1001 at 192.168.65.124:3588) State INIT
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87
sofia/internal/sip:1001 at 192.168.65.124:3588 SOFIA INIT
2014-01-30 17:53:06.482481 [DEBUG] sofia_glue.c:2738
sofia/internal/sip:1001 at 192.168.65.124:3588 sending invite version:
1.2.18 -1 64bit
Local SDP:
v=0
o=FreeSWITCH 1391074358 1391074359 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 26428 RTP/AVP 8 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1185 bytes to udp/[192.168.65.124]:3588 at 16:53:06.501475:
------------------------------------------------------------------------
INVITE sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917 SIP/2.0
Via: SIP/2.0/UDP 192.168.65.98;rport;branch=z9hG4bK27cZcy3ZyrZjj
Max-Forwards: 69
From: "Extension 1000" <sip:1000 at 192.168.65.98>;tag=5Hjea4XHZ602e
To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>
Call-ID: d5227656-0471-1232-bd8c-08002740dafd
CSeq: 55214329 INVITE
Contact: <sip:mod_sofia at 192.168.65.98:5060>
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize,
call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 203
X-FS-Support: update_display,send_info
Remote-Party-ID: "Extension 1000"
<sip:1000 at 192.168.65.98>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1391074358 1391074359 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 26428 RTP/AVP 8 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127
(sofia/internal/sip:1001 at 192.168.65.124:3588) State Change CS_INIT ->
CS_ROUTING
2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:1001 at 192.168.65.124:3588) State INIT going to
sleep
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_ROUTING
2014-01-30 17:53:06.502511 [DEBUG] sofia.c:5779 Channel
sofia/internal/sip:1001 at 192.168.65.124:3588 entering state
[calling][0]
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:1001 at 192.168.65.124:3588) State ROUTING
2014-01-30 17:53:06.502511 [DEBUG] mod_sofia.c:150
sofia/internal/sip:1001 at 192.168.65.124:3588 SOFIA ROUTING
2014-01-30 17:53:06.502511 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:1001 at 192.168.65.124:3588) State Change CS_ROUTING
-> CS_CONSUME_MEDIA
2014-01-30 17:53:06.502511 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:1001 at 192.168.65.124:3588) State ROUTING going to
sleep
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_CONSUME_MEDIA
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:1001 at 192.168.65.124:3588) State CONSUME_MEDIA
2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:1001 at 192.168.65.124:3588) State CONSUME_MEDIA
going to sleep
recv 312 bytes from udp/[192.168.65.124]:3588 at 16:53:06.583154:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj
To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>
From: "Extension 1000" <sip:1000 at 192.168.65.98>;tag=5Hjea4XHZ602e
Call-ID: d5227656-0471-1232-bd8c-08002740dafd
CSeq: 55214329 INVITE
Content-Length: 0
------------------------------------------------------------------------
recv 438 bytes from udp/[192.168.65.124]:3588 at 16:53:06.618431:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj
Contact: <sip:1001 at 192.168.65.124:3588>
To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41
From: "Extension 1000"<sip:1000 at 192.168.65.98>;tag=5Hjea4XHZ602e
Call-ID: d5227656-0471-1232-bd8c-08002740dafd
CSeq: 55214329 INVITE
User-Agent: X-Lite release 4.5.5 stamp 71241
Allow-Events: hold, talk
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:06.602764 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.602764 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:06.602764 [DEBUG] sofia.c:5779 Channel
sofia/internal/sip:1001 at 192.168.65.124:3588 entering state
[proceeding][180]
2014-01-30 17:53:06.602764 [NOTICE] sofia.c:5874 Ring-Ready
sofia/internal/sip:1001 at 192.168.65.124:3588!
2014-01-30 17:53:06.602764 [DEBUG] switch_channel.c:3239
(sofia/internal/sip:1001 at 192.168.65.124:3588) Callstate Change DOWN ->
RINGING
2014-01-30 17:53:06.622431 [INFO] switch_ivr_originate.c:1191 Sending
early media
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec
Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000]
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec
Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000]
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec
Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3184 Set Codec
sofia/internal/1000 at 192.168.65.98 PCMA/8000 20 ms 160 samples 64000
bits
2014-01-30 17:53:06.622431 [DEBUG] switch_core_codec.c:111
sofia/internal/1000 at 192.168.65.98 Original read codec set to PCMA:8
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5445 Set 2833 dtmf
send/recv payload to 96
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3443 AUDIO RTP
[sofia/internal/1000 at 192.168.65.98] 192.168.65.98 port 17870 ->
192.168.129.229 port 50040 codec: 8 ms: 20
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:2033 Starting timer
[soft] 160 bytes per 20ms
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
START SESSION INITIALIZATION. sID=0.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
ZID=633061383431363264366363.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Loading User's profile:
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
allowclear: OFF
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
autosecure: ON
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
disclose_bit: OFF
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
signal. role: Unknown
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
TTL: 4294967295
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
SAS schemes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 B256
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 B32 2014-01-30
17:53:06.622431 [DEBUG] switch_rtp.c:948
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Ciphers: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 AES3
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 AES1 2014-01-30
17:53:06.622431 [DEBUG] switch_rtp.c:948
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
PK schemes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 EC25
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 DH3k 2014-01-30
17:53:06.622431 [DEBUG] switch_rtp.c:948 DH2k 2014-01-30
17:53:06.622431 [DEBUG] switch_rtp.c:948 Mult 2014-01-30
17:53:06.622431 [DEBUG] switch_rtp.c:948
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
ATL: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 HS32
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Hashes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 S256
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Session initialization - DONE. sID=0.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
ATTACH NEW STREAM to sID=0:
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp]:
Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Empty slot was found - initializing new stream with ID=0.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
Preparing ZRTP Hello according to the Session profile.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]:
ATTACH NEW STREAM - DONE.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
START STREAM ID=0 mode=CLEAR state=ACTIVE.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp]:
Stream ID=0 CLEAR switching <ACTIVE> ---> <START>.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42140 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3710 Set 2833 dtmf
send payload to 96
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf
receive payload to 96
2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3743
sofia/internal/1000 at 192.168.65.98 Set rtp dtmf delay to 40
2014-01-30 17:53:06.622431 [NOTICE] sofia_glue.c:4354 Pre-Answer
sofia/internal/1000 at 192.168.65.98!
2014-01-30 17:53:06.622431 [DEBUG] switch_channel.c:3365
(sofia/internal/1000 at 192.168.65.98) Callstate Change RINGING -> EARLY
2014-01-30 17:53:06.622431 [DEBUG] mod_sofia.c:2885 Ring SDP:
v=0
o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 17870 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv
send 1169 bytes to udp/[192.168.5.10]:20842 at 16:53:06.630060:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22406 INVITE
Contact: <sip:1001 at 192.168.65.98:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize,
call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 219
Remote-Party-ID: "1001"
<sip:1001 at 192.168.65.98>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 17870 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
------------------------------------------------------------------------
2014-01-30 17:53:06.622431 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.622431 [DEBUG] sofia.c:5779 Channel
sofia/internal/1000 at 192.168.65.98 entering state [early][183]
2014-01-30 17:53:06.622431 [DEBUG] switch_core_session.c:871 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:06.622431 [DEBUG] switch_ivr_originate.c:1248 Raw
Codec Activation Success L16 at 8000hz 1 channel 20ms
2014-01-30 17:53:06.622431 [DEBUG] switch_core_codec.c:219
sofia/internal/1000 at 192.168.65.98 Push codec L16:70
2014-01-30 17:53:06.622431 [DEBUG] switch_ivr_originate.c:1316 Play
Ringback Tone [%(2000,4000,440,480)]
2014-01-30 17:53:06.682455 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42141 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:06.782481 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42142 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:06.882499 [INFO] switch_rtp.c:3730 Auto Changing port
from 192.168.129.229:50040 to 192.168.5.10:53756
2014-01-30 17:53:06.982476 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42143 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:07.182473 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42144 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:07.383303 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
WARNING! HELLO have been resent 5 times without a response. Raising
ZRTP_EVENT_NO_ZRTP_QUICK event. ID=0
2014-01-30 17:53:07.383303 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42145 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:07.582444 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42146 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:07.782471 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42147 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:08.002871 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42148 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:08.203152 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42149 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:08.402496 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42150 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:08.602538 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42151 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:08.803222 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42152 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:09.022481 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42153 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:09.222457 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42154 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:09.422492 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42155 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:09.622497 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42156 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:09.842523 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42157 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:10.043027 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42158 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:10.242993 [DEBUG] switch_rtp.c:948 [ zrtp utils]:
Send <HELLO> ssrc=1427653722 seq=42159 size=144. Stream
0:CLEAR:START
2014-01-30 17:53:10.442488 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
WARNING! HELLO Max retransmissions count reached (20 retries). ID=0
2014-01-30 17:53:10.442488 [DEBUG] switch_rtp.c:948 [ zrtp]:
Stream ID=0 CLEAR switching <START> ---> <NOZRTP>.
recv 455 bytes from udp/[192.168.65.124]:3588 at 16:53:11.401846:
------------------------------------------------------------------------
SIP/2.0 488 Not Acceptable Here
Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj
To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41
From: "Extension 1000"<sip:1000 at 192.168.65.98>;tag=5Hjea4XHZ602e
Call-ID: d5227656-0471-1232-bd8c-08002740dafd
CSeq: 55214329 INVITE
User-Agent: X-Lite release 4.5.5 stamp 71241
Warning: 305 devnull "SDP: Incompatible media format: no common codec"
Content-Length: 0
------------------------------------------------------------------------
send 384 bytes to udp/[192.168.65.124]:3588 at 16:53:11.403623:
------------------------------------------------------------------------
ACK sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917 SIP/2.0
Via: SIP/2.0/UDP 192.168.65.98;rport;branch=z9hG4bK27cZcy3ZyrZjj
Max-Forwards: 69
From: "Extension 1000" <sip:1000 at 192.168.65.98>;tag=5Hjea4XHZ602e
To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41
Call-ID: d5227656-0471-1232-bd8c-08002740dafd
CSeq: 55214329 ACK
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] sofia.c:5779 Channel
sofia/internal/sip:1001 at 192.168.65.124:3588 entering state
[terminated][488]
2014-01-30 17:53:11.407504 [NOTICE] sofia.c:6623 Hangup
sofia/internal/sip:1001 at 192.168.65.124:3588 [CS_CONSUME_MEDIA]
[INCOMPATIBLE_DESTINATION]
2014-01-30 17:53:11.407504 [DEBUG] switch_channel.c:3184 Send signal
sofia/internal/sip:1001 at 192.168.65.124:3588 [KILL]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_HANGUP
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:1001 at 192.168.65.124:3588) State HANGUP
2014-01-30 17:53:11.407504 [DEBUG] mod_sofia.c:506 Channel
sofia/internal/sip:1001 at 192.168.65.124:3588 hanging up, cause:
INCOMPATIBLE_DESTINATION
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:1001 at 192.168.65.124:3588 Standard HANGUP, cause:
INCOMPATIBLE_DESTINATION
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:1001 at 192.168.65.124:3588) State HANGUP going to
sleep
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:690
(sofia/internal/sip:1001 at 192.168.65.124:3588) Callstate Change RINGING
-> HANGUP
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:447
(sofia/internal/sip:1001 at 192.168.65.124:3588) State Change CS_HANGUP
-> CS_REPORTING
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_REPORTING
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:762
(sofia/internal/sip:1001 at 192.168.65.124:3588) State REPORTING
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:1001 at 192.168.65.124:3588 Standard REPORTING, cause:
INCOMPATIBLE_DESTINATION
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:762
(sofia/internal/sip:1001 at 192.168.65.124:3588) State REPORTING going to
sleep
2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:441
(sofia/internal/sip:1001 at 192.168.65.124:3588) State Change
CS_REPORTING -> CS_DESTROY
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/sip:1001 at 192.168.65.124:3588 [BREAK]
2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1559 Session
2 (sofia/internal/sip:1001 at 192.168.65.124:3588) Locked, Waiting on
external entities
2014-01-30 17:53:11.424472 [DEBUG] switch_core_codec.c:244
sofia/internal/1000 at 192.168.65.98 Restore previous codec PCMA:8.
2014-01-30 17:53:11.424472 [DEBUG] switch_ivr_originate.c:3639
Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2014-01-30 17:53:11.424472 [NOTICE] switch_ivr_originate.c:2662 Cannot
create outgoing channel of type [user] cause:
[INCOMPATIBLE_DESTINATION]
2014-01-30 17:53:11.424472 [DEBUG] switch_ivr_originate.c:3639
Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2014-01-30 17:53:11.424472 [INFO] mod_dptools.c:3201 Originate Failed.
Cause: INCOMPATIBLE_DESTINATION
EXECUTE sofia/internal/1000 at 192.168.65.98 answer()
2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:866 Local SDP
sofia/internal/1000 at 192.168.65.98:
v=0
o=FreeSWITCH 1391082916 1391082918 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 17870 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv
send 1139 bytes to udp/[192.168.5.10]:20842 at 16:53:11.430754:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22406 INVITE
Contact: <sip:1001 at 192.168.65.98:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize,
call-info, sla, include-session-description, presence.winfo,
message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 219
Remote-Party-ID: "Outbound Call"
<sip:1001 at 192.168.65.98>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98
s=FreeSWITCH
c=IN IP4 192.168.65.98
t=0 0
m=audio 17870 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
------------------------------------------------------------------------
2014-01-30 17:53:11.424472 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:11.424472 [DEBUG] sofia.c:5779 Channel
sofia/internal/1000 at 192.168.65.98 entering state [completed][200]
2014-01-30 17:53:11.424472 [DEBUG] switch_core_session.c:871 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:11.424472 [NOTICE] mod_dptools.c:1225 Channel
[sofia/internal/1000 at 192.168.65.98] has been answered
2014-01-30 17:53:11.424472 [DEBUG] switch_channel.c:3644
(sofia/internal/1000 at 192.168.65.98) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/internal/1000 at 192.168.65.98 sleep(1000)
2014-01-30 17:53:11.424472 [NOTICE] switch_core_session.c:1577 Session
2 (sofia/internal/sip:1001 at 192.168.65.124:3588) Ended
2014-01-30 17:53:11.424472 [NOTICE] switch_core_session.c:1581 Close
Channel sofia/internal/sip:1001 at 192.168.65.124:3588 [CS_DESTROY]
2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:566
(sofia/internal/sip:1001 at 192.168.65.124:3588) Callstate Change HANGUP
-> DOWN
2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:1001 at 192.168.65.124:3588) Running State Change
CS_DESTROY
2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:1001 at 192.168.65.124:3588) State DESTROY
2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:399
sofia/internal/sip:1001 at 192.168.65.124:3588 SOFIA DESTROY
2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:1001 at 192.168.65.124:3588 Standard DESTROY
2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:1001 at 192.168.65.124:3588) State DESTROY going to
sleep
recv 410 bytes from udp/[192.168.5.10]:20842 at 16:53:11.464680:
------------------------------------------------------------------------
ACK sip:1001 at 192.168.65.98:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPjdd90edd2522045c79127fa96e72c6487
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22406 ACK
User-Agent: Blink 0.6.0 (Windows)
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:11.488073 [DEBUG] sofia.c:5779 Channel
sofia/internal/1000 at 192.168.65.98 entering state [ready][200]
EXECUTE sofia/internal/1000 at 192.168.65.98
bridge(loopback/app=voicemail:default 192.168.65.98 1001)
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1765
(sofia/internal/1000 at 192.168.65.98) Callstate Change ACTIVE ->
RING_WAIT
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1198
sofia/internal/1000 at 192.168.65.98 EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:2061 Parsing
global variables
2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1052 New Channel
loopback/app=voicemail:default 192.168.65.98 1001-a
[0ec9cff0-d6ff-48f7-8cbe-4b18a663e7cb]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:157
loopback/app=voicemail:default 192.168.65.98 1001-a setup codec
PCMA/8000/20
2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1050 Rename
Channel loopback/app=voicemail:default 192.168.65.98
1001-a->loopback/voicemail-a [0ec9cff0-d6ff-48f7-8cbe-4b18a663e7cb]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:1158
(loopback/voicemail-a) State Change CS_NEW -> CS_INIT
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_INIT
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-a) State INIT
2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1052 New Channel
loopback/voicemail-b [89b050fa-b391-488f-882b-ca3607f1dabd]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:157
loopback/voicemail-b setup codec PCMA/8000/20
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:272
(loopback/voicemail-b) State Change CS_NEW -> CS_INIT
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:357
(loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-a) State INIT going to sleep
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_ROUTING
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-a) State ROUTING
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:389
loopback/voicemail-a CHANNEL ROUTING
2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:67
(loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-a) State ROUTING going to sleep
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:490
(loopback/voicemail-a) State CONSUME_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:648 CHANNEL CONSUME_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:490
(loopback/voicemail-a) State CONSUME_MEDIA going to sleep
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_INIT
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-b) State INIT
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:357
(loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-b) State INIT going to sleep
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_ROUTING
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:2165
(loopback/voicemail-b) Callstate Change DOWN -> RINGING
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-b) State ROUTING
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:389
loopback/voicemail-b CHANNEL ROUTING
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:408
(loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-b) State ROUTING going to sleep
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_EXECUTE
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:478
(loopback/voicemail-b) State EXECUTE
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:431
loopback/voicemail-b CHANNEL EXECUTE
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:209
loopback/voicemail-b Standard EXECUTE
EXECUTE loopback/voicemail-b pre_answer()
2014-01-30 17:53:12.442539 [NOTICE] mod_loopback.c:945 Pre-Answer
loopback/voicemail-a!
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3361 Send signal
sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3365
(loopback/voicemail-a) Callstate Change DOWN -> EARLY
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:12.442539 [NOTICE] mod_dptools.c:1260 Pre-Answer
loopback/voicemail-b!
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3365
(loopback/voicemail-b) Callstate Change RINGING -> EARLY
EXECUTE loopback/voicemail-b voicemail(default 192.168.65.98 1001)
2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:3495
Originate Resulted in Success: [loopback/voicemail-a]
2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1969
(sofia/internal/1000 at 192.168.65.98) Callstate Change RING_WAIT ->
ACTIVE
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_bridge.c:1426
(loopback/voicemail-a) State Change CS_CONSUME_MEDIA ->
CS_EXCHANGE_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:481
(loopback/voicemail-a) State EXCHANGE_MEDIA
2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:610 CHANNEL LOOPBACK
2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:70 No
language specified - Using [en]
2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-person.wav] (en:en)
2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-01-30 17:53:13.922469 [DEBUG] switch_ivr_play_say.c:1717 done
playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
2014-01-30 17:53:14.023721 [DEBUG] switch_ivr_play_say.c:251 Handle
say:[1001] (en:en)
2014-01-30 17:53:14.023721 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-01-30 17:53:16.263327 [DEBUG] switch_ivr_play_say.c:1717 done
playing file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav
2014-01-30 17:53:16.363379 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-not_available.wav] (en:en)
2014-01-30 17:53:16.363379 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-01-30 17:53:17.342459 [DEBUG] switch_ivr_play_say.c:1717 done
playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:70 No
language specified - Using [en]
2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-record_message.wav] (en:en)
2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
recv 410 bytes from udp/[192.168.5.10]:20842 at 16:53:18.270540:
------------------------------------------------------------------------
BYE sip:1001 at 192.168.65.98:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP
192.168.129.229:2425;rport;branch=z9hG4bKPje4e3e31a701c4d77b2b7d5dde2de9f6d
Max-Forwards: 70
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22407 BYE
User-Agent: Blink 0.6.0 (Windows)
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:18.262629 [DEBUG] switch_core_session.c:1016 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:18.283431 [NOTICE] sofia.c:737 Hangup
sofia/internal/1000 at 192.168.65.98 [CS_EXECUTE] [NORMAL_CLEARING]
2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal
sofia/internal/1000 at 192.168.65.98 [KILL]
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
send 552 bytes to udp/[192.168.5.10]:20842 at 16:53:18.284629:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.129.229:2425;rport=20842;branch=z9hG4bKPje4e3e31a701c4d77b2b7d5dde2de9f6d;received=192.168.5.10
From: "thomas" <sip:1000 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
Call-ID: bb25748be1f94505a7132e68f5576bae
CSeq: 22407 BYE
User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:633 BRIDGE
THREAD DONE [sofia/internal/1000 at 192.168.65.98]
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:658 Send signal
loopback/voicemail-a [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:557
sofia/internal/1000 at 192.168.65.98 ending bridge by request from write
function
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:633 BRIDGE
THREAD DONE [loopback/voicemail-a]
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:658 Send signal
sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:18.283431 [NOTICE] switch_ivr_bridge.c:719 Hangup
loopback/voicemail-a [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal
loopback/voicemail-a [KILL]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:481
(loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_HANGUP
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679
(loopback/voicemail-a) State HANGUP
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:535
loopback/voicemail-a CHANNEL HANGUP
2014-01-30 17:53:18.283431 [NOTICE] mod_loopback.c:551 Hangup
loopback/voicemail-b [CS_EXECUTE] [ORIGINATOR_CANCEL]
2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal
loopback/voicemail-b [KILL]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:48
loopback/voicemail-a Standard HANGUP, cause: ORIGINATOR_CANCEL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679
(loopback/voicemail-a) State HANGUP going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:690
(loopback/voicemail-a) Callstate Change EARLY -> HANGUP
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:447
(loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762
(loopback/voicemail-a) State REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:92
loopback/voicemail-a Standard REPORTING, cause: ORIGINATOR_CANCEL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762
(loopback/voicemail-a) State REPORTING going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:441
(loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-a [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588
loopback/voicemail-a CHANNEL KILL
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1559 Session
3 (loopback/voicemail-a) Locked, Waiting on external entities
2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:1527
sofia/internal/1000 at 192.168.65.98 skip receive message [UNBRIDGE]
(channel is hungup already)
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:2810
sofia/internal/1000 at 192.168.65.98 skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:478
(sofia/internal/1000 at 192.168.65.98) State EXECUTE going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_HANGUP
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/1000 at 192.168.65.98) State HANGUP
2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:500
sofia/internal/1000 at 192.168.65.98 Overriding SIP cause 480 with 488
from the other leg
2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:506 Channel
sofia/internal/1000 at 192.168.65.98 hanging up, cause: NORMAL_CLEARING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:48
sofia/internal/1000 at 192.168.65.98 Standard HANGUP, cause:
NORMAL_CLEARING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/1000 at 192.168.65.98) State HANGUP going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:690
(sofia/internal/1000 at 192.168.65.98) Callstate Change ACTIVE -> HANGUP
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:447
(sofia/internal/1000 at 192.168.65.98) State Change CS_HANGUP ->
CS_REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762
(sofia/internal/1000 at 192.168.65.98) State REPORTING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:92
sofia/internal/1000 at 192.168.65.98 Standard REPORTING, cause:
NORMAL_CLEARING
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762
(sofia/internal/1000 at 192.168.65.98) State REPORTING going to sleep
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:441
(sofia/internal/1000 at 192.168.65.98) State Change CS_REPORTING ->
CS_DESTROY
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
signal sofia/internal/1000 at 192.168.65.98 [BREAK]
2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1559 Session
1 (sofia/internal/1000 at 192.168.65.98) Locked, Waiting on external
entities
2014-01-30 17:53:18.283431 [NOTICE] switch_core_session.c:1577 Session
1 (sofia/internal/1000 at 192.168.65.98) Ended
2014-01-30 17:53:18.283431 [NOTICE] switch_core_session.c:1581 Close
Channel sofia/internal/1000 at 192.168.65.98 [CS_DESTROY]
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:566
(sofia/internal/1000 at 192.168.65.98) Callstate Change HANGUP -> DOWN
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/1000 at 192.168.65.98) Running State Change CS_DESTROY
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/1000 at 192.168.65.98) State DESTROY
2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:399
sofia/internal/1000 at 192.168.65.98 SOFIA DESTROY
2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
STOP STREAM ID=0 mode=CLEAR state=NOZRTP.
2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp]:
Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>.
2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:99
sofia/internal/1000 at 192.168.65.98 Standard DESTROY
2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/1000 at 192.168.65.98) State DESTROY going to sleep
2014-01-30 17:53:18.302529 [DEBUG] switch_ivr_play_say.c:1717 done
playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav
2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:2810
loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
(channel is hungup already)
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:478
(loopback/voicemail-b) State EXECUTE going to sleep
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_HANGUP
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:679
(loopback/voicemail-b) State HANGUP
2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:535
loopback/voicemail-b CHANNEL HANGUP
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:48
loopback/voicemail-b Standard HANGUP, cause: ORIGINATOR_CANCEL
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:679
(loopback/voicemail-b) State HANGUP going to sleep
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:690
(loopback/voicemail-b) Callstate Change EARLY -> HANGUP
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:447
(loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_REPORTING
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:762
(loopback/voicemail-b) State REPORTING
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:92
loopback/voicemail-b Standard REPORTING, cause: ORIGINATOR_CANCEL
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:762
(loopback/voicemail-b) State REPORTING going to sleep
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:441
(loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1351 Send
signal loopback/voicemail-b [BREAK]
2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:588
loopback/voicemail-b CHANNEL KILL
2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1559 Session
4 (loopback/voicemail-b) Locked, Waiting on external entities
2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1577 Session
4 (loopback/voicemail-b) Ended
2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1581 Close
Channel loopback/voicemail-b [CS_DESTROY]
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:566
(loopback/voicemail-b) Callstate Change HANGUP -> DOWN
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:569
(loopback/voicemail-b) Running State Change CS_DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-b) State DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:99
loopback/voicemail-b Standard DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-b) State DESTROY going to sleep
2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1577 Session
3 (loopback/voicemail-a) Ended
2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1581 Close
Channel loopback/voicemail-a [CS_DESTROY]
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:566
(loopback/voicemail-a) Callstate Change HANGUP -> DOWN
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:569
(loopback/voicemail-a) Running State Change CS_DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-a) State DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:99
loopback/voicemail-a Standard DESTROY
2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-a) State DESTROY going to sleep
recv 2307 bytes from udp/[192.168.5.10]:20842 at 16:53:18.329959:
---------------------
one client (blink, 1000) supports only PCMA, the other client (bria,
1001) supports only PCMU. i didnt touch the default config of the
freeswitch on a debian system.
thank you very much for help!
best,
thomas
2014-01-28 Brian West <brian at freeswitch.org>:
> Logs, with sip trace on please.
>
> --
> Brian West
> brian at freeswitch.org
> FreeSWITCH Solutions, LLC
> PO BOX 2531
> Brookfield, WI 53008-2531
> Twitter: @FreeSWITCH , @briankwest
> http://www.freeswitchbook.com
> http://www.freeswitchcookbook.com
>
> T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST
> iNUM: +883 5100 1420 9001
> ISN: 410*543
> Skype:briankwest
> PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
>
>
>
>
>
>
>
>
>
>
>
>
>
> On Jan 28, 2014, at 9:13 AM, thomas peterseil <thomas.peterseil at gmail.com> wrote:
>
>> i have the same problem. i am running a FS with the default config
>> 1000 supports only PCMA and 1001 only PCMU (one client is blink, the
>> other jitsi), the call between 1000 and 1001 doesnt work. as soon as i
>> enable the same codecs on both clients, it works without any problem.
>> thanks a lot for your help!
>>
>> best regards,
>> thomas
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users
mailing list