[Freeswitch-users] How to configure G722 for internal and G729 for external calls

10 Mar 2015

      hi,

I'm trying to get freeswitch to use G722 for internal calls and G729 for
external calls.

I'm using vanilla.

Am I missing something obvious here?

in vars.xml I have:

  <X-PRE-PROCESS cmd="set"
data="global_codec_prefs=OPUS,G722,PCMU,PCMA,GSM"/>
  <X-PRE-PROCESS cmd="set" data="outbound_codec_prefs=G729"/>

when I place a call to an external number, it gets encoded as G722,
according to the CDR:

"1001","1001","938xxxxxx","default","2015-03-09 16:52:45","2015-03-09
16:52:48","2015-03-09
16:54:03","78","75","NORMAL_CLEARING","1ee1cfd1-f35c-4829-803a-771678574d07","cb8ee2cc-46bb-45d2-b302-effe038f195e","1001","G722","G722"

Dialplan:
  <extension name="pennytel-local_fixed_line">
    <condition field="destination_number" expression="^([2-9]{1}[0-9]{7})$">
      <action application="set" data="sip_h_X-accountcode=${accountcode}"/>
      <action application="set" data="call_direction=outbound"/>
      <action application="set" data="hangup_after_bridge=true"/>
      <action application="set"
data="effective_caller_id_name=${outbound_caller_id_name}"/>
      <action application="set"
data="effective_caller_id_number=${outbound_caller_id_number}"/>
      <action application="bridge"
data="{absolute_codec_string='G729'}sofia/gateway/pennytel/612$1"/>
    </condition>
  </extension>

restarting the external gateway shows the outbound codec preference is
there:

freeswitch@internal> sofia profile external restart reloadxml
Reload XML [Success]
restarting: external
freeswitch@internal> 2015-03-10 12:33:04.175760 [INFO] mod_enum.c:880
ENUM Reloaded
2015-03-10 12:33:04.175760 [INFO] switch_time.c:1411 Timezone reloaded
1781 definitions
2015-03-10 12:33:04.315790 [NOTICE] sofia_reg.c:135 UN-Registering sip2sip
2015-03-10 12:33:04.315790 [NOTICE] sofia_reg.c:135 UN-Registering pennytel
2015-03-10 12:33:05.315785 [NOTICE] sofia.c:3044 Waiting for worker thread
2015-03-10 12:33:05.315785 [INFO] switch_core_sqldb.c:1701
sofia:external Destroying SQL queue.
2015-03-10 12:33:05.515828 [INFO] switch_core_sqldb.c:1664
sofia:external Stopping SQL thread.
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:3099 Write lock external
2015-03-10 12:33:05.515828 [NOTICE] sofia_glue.c:1814 deleted gateway
example.com from profile external
2015-03-10 12:33:05.515828 [NOTICE] sofia_glue.c:1814 deleted gateway
sip2sip from profile external
2015-03-10 12:33:05.515828 [NOTICE] sofia_glue.c:1814 deleted gateway
pennytel from profile external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:3112 Write unlock external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 debug [0]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 sip-trace [no]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 sip-capture [no]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 rfc2833-pt [101]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 sip-port [5080]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 dialplan [XML]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 context [public]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 dtmf-duration [2000]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 inbound-codec-prefs
[OPUS,G722,PCMU,PCMA,GSM]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 outbound-codec-prefs [G729]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 hold-music
[local_stream://moh/8000]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 rtp-timer-name [soft]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 local-network-acl
[localnet.auto]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 manage-presence [false]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146
inbound-codec-negotiation [generous]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 nonce-ttl [60]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 auth-calls [false]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 inbound-late-negotiation
[true]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 inbound-zrtp-passthru [true]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 rtp-ip [10.0.2.145]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 sip-ip [10.0.2.145]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 ext-rtp-ip [aa.bb.cc.dd]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 ext-sip-ip [aa.bb.cc.dd]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 rtp-timeout-sec [300]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 rtp-hold-timeout-sec [1800]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls [false]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-only [false]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-bind-params
[transport=tls]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-sip-port [5081]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-passphrase []
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-verify-date [true]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-verify-policy [none]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-verify-depth [2]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-verify-in-subjects []
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:4146 tls-version
[tlsv1,tlsv1.1,tlsv1.2]
2015-03-10 12:33:05.515828 [NOTICE] sofia.c:5557 Started Profile
external [sofia_reg_external]
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:2755 Creating agent for external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:2873 Created agent for external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:2918 Set params for external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:2962 Activated db for external
2015-03-10 12:33:05.515828 [INFO] switch_core_sqldb.c:1679
sofia:external Starting SQL thread.
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:3000 Starting thread for external
2015-03-10 12:33:05.515828 [DEBUG] sofia.c:2655 Launching worker thread
for external
2015-03-10 12:33:05.515828 [NOTICE] sofia_reg.c:3329 Added gateway
'pennytel' to profile 'external'
2015-03-10 12:33:05.515828 [NOTICE] sofia_reg.c:3329 Added gateway
'sip2sip' to profile 'external'
2015-03-10 12:33:05.515828 [NOTICE] sofia_reg.c:3329 Added gateway
'example.com' to profile 'external'
2015-03-10 12:33:05.515828 [NOTICE] sofia_reg.c:448 Registering sip2sip
2015-03-10 12:33:05.515828 [NOTICE] sofia_reg.c:448 Registering pennytel

Dialing out, I get these logs:

2015-03-10 12:37:37.615813 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.615813 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.615813 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_NEW
2015-03-10 12:37:37.635769 [DEBUG] sofia.c:8834
sofia/internal/1001@freeswitch.xyz.com.au receiving invite from
10.0.2.129:5062 version: 1.4.15 -1 64bit
2015-03-10 12:37:37.635769 [DEBUG] sofia.c:9001 IP 10.0.2.129 Rejected
by acl "domains". Falling back to Digest auth.
2015-03-10 12:37:37.635769 [DEBUG] switch_core_state_machine.c:491
(sofia/internal/1001@freeswitch.xyz.com.au) State NEW
2015-03-10 12:37:37.635769 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.635769 [DEBUG] sofia.c:2067 detaching session
38291425-a146-4aa2-a129-854757744bc1
2015-03-10 12:37:37.755808 [DEBUG] sofia.c:2175 Re-attaching to session
38291425-a146-4aa2-a129-854757744bc1
2015-03-10 12:37:37.755808 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.755808 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] sofia.c:8834
sofia/internal/1001@freeswitch.xyz.com.au receiving invite from
10.0.2.129:5062 version: 1.4.15 -1 64bit
2015-03-10 12:37:37.775786 [DEBUG] sofia.c:9001 IP 10.0.2.129 Rejected
by acl "domains". Falling back to Digest auth.
2015-03-10 12:37:37.775786 [DEBUG] sofia.c:6614 Channel
sofia/internal/1001@freeswitch.xyz.com.au entering state [received][100]
2015-03-10 12:37:37.775786 [DEBUG] sofia.c:6624 Remote SDP:
v=0
o=- 20183 20183 IN IP4 10.0.2.129
s=SDP data
c=IN IP4 10.0.2.129
t=0 0
m=audio 11794 RTP/AVP 18 9 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2015-03-10 12:37:37.775786 [DEBUG] sofia.c:6890
(sofia/internal/1001@freeswitch.xyz.com.au) State Change CS_NEW -> CS_INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:512
(sofia/internal/1001@freeswitch.xyz.com.au) State INIT
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:87
sofia/internal/1001@freeswitch.xyz.com.au SOFIA INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:40
sofia/internal/1001@freeswitch.xyz.com.au Standard INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/1001@freeswitch.xyz.com.au) State Change CS_INIT ->
CS_ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:512
(sofia/internal/1001@freeswitch.xyz.com.au) State INIT going to sleep
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_channel.c:2184
(sofia/internal/1001@freeswitch.xyz.com.au) Callstate Change DOWN -> RINGING
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:528
(sofia/internal/1001@freeswitch.xyz.com.au) State ROUTING
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:123
sofia/internal/1001@freeswitch.xyz.com.au SOFIA ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:166
sofia/internal/1001@freeswitch.xyz.com.au Standard ROUTING
2015-03-10 12:37:37.775786 [INFO] mod_dialplan_xml.c:635 Processing 1001
<1001>->775 in context default
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->unloop] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS)
[unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->tod_example] continue=true
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Date/Time Match
(PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action set(open=true)
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Date/TimeMatch
(FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[global-intercept] destination_number(775) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[group-intercept] destination_number(775) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[intercept-ext] destination_number(775) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->redial] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[redial] destination_number(775) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->global] continue=true
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[global] ${default_password}(18651) =~ /^1234$/ break=never
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[global] ${rtp_has_crypto}() =~
/^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/
break=never
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS)
[global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED
NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[global] ${switch_r_sdp}(v=0
o=- 20183 20183 IN IP4 10.0.2.129
s=SDP data
c=IN IP4 10.0.2.129
t=0 0
m=audio 11794 RTP/AVP 18 9 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Absolute Condition
[global]
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->snom-demo-2] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[snom-demo-2] destination_number(775) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[snom-demo-1] destination_number(775) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[eavesdrop] destination_number(775) =~ /^88(\d{4})$|^\*0(.*)$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[eavesdrop] destination_number(775) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->call_return] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[call_return] destination_number(775) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->del-group] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[del-group] destination_number(775) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->add-group] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[add-group] destination_number(775) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[call-group-simo] destination_number(775) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[call-group-order] destination_number(775) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[extension-intercom] destination_number(775) =~ /^8(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->SIPTAPI-AutoAnswer] continue=true
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[SIPTAPI-AutoAnswer] ${sip_user_agent}(Yealink SIP-T42G 29.73.0.45) =~
/.*SIPTAPI.*/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[Local_Extension] destination_number(775) =~ /^(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->Local_Extension_Skinny] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[Local_Extension_Skinny] destination_number(775) =~ /^(11[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->group_dial_sales] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[group_dial_sales] destination_number(775) =~ /^2000$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->group_dial_support] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[group_dial_support] destination_number(775) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->group_dial_billing] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[group_dial_billing] destination_number(775) =~ /^2002$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->group_dial_custom] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[group_dial_custom] destination_number(775) =~ /^2003$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->operator] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[operator] destination_number(775) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->vmain] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [vmain]
destination_number(775) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->sip_uri] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[sip_uri] destination_number(775) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->nb_conferences] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[nb_conferences] destination_number(775) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->wb_conferences] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[wb_conferences] destination_number(775) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->uwb_conferences] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[uwb_conferences] destination_number(775) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->cdquality_conferences] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[cdquality_conferences] destination_number(775) =~ /^(33\d{2})$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[freeswitch_public_conf_via_sip] destination_number(775) =~
/^9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[mad_boss_intercom] destination_number(775) =~ /^0911$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[mad_boss_intercom] destination_number(775) =~ /^0912$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->mad_boss] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[mad_boss] destination_number(775) =~ /^0913$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ivr_demo] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ivr_demo] destination_number(775) =~ /^5000$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->dynamic_conference] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[dynamic_conference] destination_number(775) =~ /^5001$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->rtp_multicast_page] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[rtp_multicast_page] destination_number(775) =~ /^pagegroup$|^7243$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->park] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [park]
destination_number(775) =~ /^5900$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->unpark] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[unpark] destination_number(775) =~ /^5901$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->valet_park] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[valet_park] destination_number(775) =~ /^(6000)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->valet_park] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[valet_park] destination_number(775) =~ /^((?!6000)60\d{2})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->park] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [park]
destination_number(775) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->unpark] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS)
[unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[unpark] destination_number(775) =~ /^parking$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->park] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [park]
destination_number(775) =~ /callpark/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->unpark] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS)
[unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[unpark] destination_number(775) =~ /pickup/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->wait] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [wait]
destination_number(775) =~ /^wait$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->fax_receive] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[fax_receive] destination_number(775) =~ /^9178$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->fax_transmit] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[fax_transmit] destination_number(775) =~ /^9179$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ringback_180] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ringback_180] destination_number(775) =~ /^9180$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ringback_183_uk_ring] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ringback_183_uk_ring] destination_number(775) =~ /^9181$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ringback_183_music_ring] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ringback_183_music_ring] destination_number(775) =~ /^9182$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ringback_post_answer_uk_ring] destination_number(775) =~ /^9183$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ringback_post_answer_music] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ringback_post_answer_music] destination_number(775) =~ /^9184$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->ClueCon] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[ClueCon] destination_number(775) =~ /^9191$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->show_info] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[show_info] destination_number(775) =~ /^9192$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->video_record] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[video_record] destination_number(775) =~ /^9193$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->video_playback] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[video_playback] destination_number(775) =~ /^9194$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->delay_echo] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[delay_echo] destination_number(775) =~ /^9195$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->echo] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [echo]
destination_number(775) =~ /^9196$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->milliwatt] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[milliwatt] destination_number(775) =~ /^9197$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->tone_stream] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[tone_stream] destination_number(775) =~ /^9198$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->zrtp_enrollement] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[zrtp_enrollement] destination_number(775) =~ /^9787$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->hold_music] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[hold_music] destination_number(775) =~ /^9664$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->laugh break] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [laugh
break] destination_number(775) =~ /^9386$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->101] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL) [101]
destination_number(775) =~ /^101$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pizza_demo] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pizza_demo] destination_number(775) =~ /^(pizza|74992)$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->Talking Clock Time] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[Talking Clock Time] destination_number(775) =~ /^9170$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->Talking Clock Date] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[Talking Clock Date] destination_number(775) =~ /^9171$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->Talking Clock Date and Time] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[Talking Clock Date and Time] destination_number(775) =~ /^9172$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-local_fixed_line] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pennytel-local_fixed_line] destination_number(775) =~
/^([2-9]{1}[0-9]{7})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-national_fixed_line] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pennytel-national_fixed_line] destination_number(775) =~
/^(0|61|\+61)?([2?|3|5-9]{1}[0-9]{8})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-national_mobiles] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pennytel-national_mobiles] destination_number(775) =~
/^(0|61|\+61)?(4{1}[0-9]{8})$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-13] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pennytel-13] destination_number(775) =~ /^13(\d{4}|00\d{6})$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-18] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (FAIL)
[pennytel-18] destination_number(775) =~ /^180(\d{4}|0\d{6})$/
break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au parsing
[default->pennytel-test] continue=false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Regex (PASS)
[pennytel-test] destination_number(775) =~ /^775$/ break=on-false
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
set(call_direction=outbound)
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/1001@freeswitch.xyz.com.au Action
bridge({absolute_codec_string='G729'}sofia/gateway/pennytel/775)
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:216
(sofia/internal/1001@freeswitch.xyz.com.au) State Change CS_ROUTING ->
CS_EXECUTE
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:528
(sofia/internal/1001@freeswitch.xyz.com.au) State ROUTING going to sleep
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_EXECUTE
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/1001@freeswitch.xyz.com.au) State EXECUTE
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:178
sofia/internal/1001@freeswitch.xyz.com.au SOFIA EXECUTE
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:258
sofia/internal/1001@freeswitch.xyz.com.au Standard EXECUTE
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au set(open=true)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET [open]=[true]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
hash(insert/freeswitch.xyz.com.au-spymap/1001/38291425-a146-4aa2-a129-854757744bc1)
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
hash(insert/freeswitch.xyz.com.au-last_dial/1001/775)
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
hash(insert/freeswitch.xyz.com.au-last_dial/global/38291425-a146-4aa2-a129-854757744bc1)
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
export(RFC2822_DATE=Tue, 10 Mar 2015 12:37:37 +1100)
2015-03-10 12:37:37.775786 [DEBUG] switch_channel.c:1247 EXPORT
(export_vars) [RFC2822_DATE]=[Tue, 10 Mar 2015 12:37:37 +1100]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
set(sip_h_X-accountcode=1001)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET [sip_h_X-accountcode]=[1001]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
set(call_direction=outbound)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET [call_direction]=[outbound]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
set(hangup_after_bridge=true)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
set(effective_caller_id_name=FreeSWITCH)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET
[effective_caller_id_name]=[FreeSWITCH]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
set(effective_caller_id_number=0000000000)
2015-03-10 12:37:37.775786 [DEBUG] mod_dptools.c:1435
sofia/internal/1001@freeswitch.xyz.com.au SET
[effective_caller_id_number]=[0000000000]
EXECUTE sofia/internal/1001@freeswitch.xyz.com.au
bridge({absolute_codec_string='G729'}sofia/gateway/pennytel/775)
2015-03-10 12:37:37.775786 [DEBUG] switch_channel.c:1201
sofia/internal/1001@freeswitch.xyz.com.au EXPORTING[export_vars]
[RFC2822_DATE]=[Tue, 10 Mar 2015 12:37:37 +1100] to event
2015-03-10 12:37:37.775786 [DEBUG] switch_ivr_originate.c:2103 Parsing
global variables
2015-03-10 12:37:37.775786 [DEBUG] switch_event.c:1688 Parsing variable
[absolute_codec_string]=[G729]
2015-03-10 12:37:37.775786 [NOTICE] switch_channel.c:1055 New Channel
sofia/external/775 [a6bc5be8-d538-4b72-892f-6e7c26f6dea6]
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:4627 (sofia/external/775)
State Change CS_NEW -> CS_INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:4697 [zrtp_passthru]
Setting a-leg inherit_codec=true
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:4700 [zrtp_passthru]
Setting b-leg
absolute_codec_string='G722@8000h@20i@64000b,PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b'
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:512
(sofia/external/775) State INIT
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:87 sofia/external/775
SOFIA INIT
2015-03-10 12:37:37.775786 [DEBUG] sofia_glue.c:1232 sofia/external/775
sending invite version: 1.4.15 -1 64bit
Local SDP:
v=0
o=FreeSWITCH 1425927473 1425927474 IN IP4 aa.bbb.ccc.ddd
s=FreeSWITCH
c=IN IP4 aa.bbb.ccc.ddd
t=0 0
m=audio 23984 RTP/AVP 18 101 13
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:40
sofia/external/775 Standard INIT
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:48
(sofia/external/775) State Change CS_INIT -> CS_ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:512
(sofia/external/775) State INIT going to sleep
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] sofia.c:6614 Channel
sofia/external/775 entering state [calling][0]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:528
(sofia/external/775) State ROUTING
2015-03-10 12:37:37.775786 [DEBUG] mod_sofia.c:123 sofia/external/775
SOFIA ROUTING
2015-03-10 12:37:37.775786 [DEBUG] switch_ivr_originate.c:67
(sofia/external/775) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2015-03-10 12:37:37.775786 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:528
(sofia/external/775) State ROUTING going to sleep
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_CONSUME_MEDIA
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:547
(sofia/external/775) State CONSUME_MEDIA
2015-03-10 12:37:37.775786 [DEBUG] switch_core_state_machine.c:547
(sofia/external/775) State CONSUME_MEDIA going to sleep
2015-03-10 12:37:38.315813 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.315813 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.315813 [DEBUG] sofia.c:6614 Channel
sofia/external/775 entering state [calling][0]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.735794 [DEBUG] sofia.c:6614 Channel
sofia/external/775 entering state [completing][200]
2015-03-10 12:37:38.735794 [DEBUG] sofia.c:6624 Remote SDP:
v=0
o=Sippy 2433467651418324771 2 IN IP4 202.85.243.105
s=session
t=0 0
m=audio 10948 RTP/AVP 18 101
c=IN IP4 202.85.243.53
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

2015-03-10 12:37:38.735794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.735794 [DEBUG] sofia.c:6614 Channel
sofia/external/775 entering state [ready][200]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3682 Audio Codec
Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3543 Set
telephone-event payload to 101
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:2473 Set Codec
sofia/external/775 G729/8000 20 ms 160 samples 8000 bits 1 channels
2015-03-10 12:37:38.735794 [DEBUG] switch_core_codec.c:111
sofia/external/775 Original read codec set to G729:18
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3881 Set 2833
dtmf send payload to 101
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:5141 AUDIO RTP
[sofia/external/775] 10.0.2.145 port 23984 -> 202.85.243.53 port 10948
codec: 18 ms: 20
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:3548 Starting timer
[soft] 160 bytes per 20ms
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
START SESSION INITIALIZATION. sID=61.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ZID=306130303032393164366363.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
Loading User's profile:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
allowclear: OFF
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
autosecure: ON
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]: 
disclose_bit: OFF
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]: 
signal. role: Initiator
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:           TTL: 4294967295
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
SAS schemes:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 B256
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 B32
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:      Ciphers:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 AES3
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 AES1
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
PK schemes:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 EC25
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 DH3k
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 DH2k
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 Mult
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:           ATL:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 HS32
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:       Hashes:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357 S256
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
Session initialization - DONE. sID=61.

2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ATTACH NEW STREAM to sID=61:
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
Empty slot was found - initializing new stream with ID=61.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
Preparing ZRTP Hello according to the Session profile.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ATTACH NEW STREAM - DONE.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
START STREAM ID=61 mode=CLEAR state=ACTIVE.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=61 CLEAR switching <ACTIVE> ---> <START>.
2015-03-10 12:37:38.735794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6662 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:5439 Set 2833
dtmf send payload to 101
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:5445 Set 2833
dtmf receive payload to 101
2015-03-10 12:37:38.735794 [DEBUG] switch_channel.c:3635 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.735794 [NOTICE] sofia.c:7475 Channel
[sofia/external/775] has been answered
2015-03-10 12:37:38.735794 [DEBUG] switch_channel.c:3689
(sofia/external/775) Callstate Change DOWN -> ACTIVE
2015-03-10 12:37:38.735794 [DEBUG] switch_ivr_originate.c:415 Codec
string G729@8000h@20i not supported on
sofia/internal/1001@freeswitch.xyz.com.au, skipping inheritance
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3682 Audio Codec
Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3682 Audio Codec
Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3682 Audio Codec
Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2015-03-10 12:37:38.735794 [DEBUG] switch_core_media.c:3543 Set
telephone-event payload to 101
2015-03-10 12:37:38.755785 [DEBUG] switch_core_media.c:2473 Set Codec
sofia/internal/1001@freeswitch.xyz.com.au G722/8000 20 ms 160 samples
64000 bits 1 channels
2015-03-10 12:37:38.755785 [DEBUG] switch_core_codec.c:111
sofia/internal/1001@freeswitch.xyz.com.au Original read codec set to G722:9
2015-03-10 12:37:38.755785 [DEBUG] switch_core_media.c:3890 Set 2833
dtmf send/recv payload to 101
2015-03-10 12:37:38.755785 [DEBUG] switch_core_media.c:5141 AUDIO RTP
[sofia/internal/1001@freeswitch.xyz.com.au] 10.0.2.145 port 20762 ->
10.0.2.129 port 11794 codec: 9 ms: 20
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:3548 Starting timer
[soft] 160 bytes per 20ms
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
START SESSION INITIALIZATION. sID=62.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ZID=306130303032393164366363.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
Loading User's profile:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
allowclear: OFF
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
autosecure: ON
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]: 
disclose_bit: OFF
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]: 
signal. role: Unknown
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:           TTL: 4294967295
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
SAS schemes:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 B256
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 B32
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:      Ciphers:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 AES3
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 AES1
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:   
PK schemes:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 EC25
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 DH3k
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 DH2k
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 Mult
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:           ATL:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 HS32
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp
main]:       Hashes:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357 S256
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
Session initialization - DONE. sID=62.

2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ATTACH NEW STREAM to sID=62:
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
Empty slot was found - initializing new stream with ID=62.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:  
Preparing ZRTP Hello according to the Session profile.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [   zrtp main]:
ATTACH NEW STREAM - DONE.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
START STREAM ID=62 mode=CLEAR state=ACTIVE.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=62 CLEAR switching <ACTIVE> ---> <START>.
2015-03-10 12:37:38.755785 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16177 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:38.755785 [DEBUG] switch_core_media.c:5439 Set 2833
dtmf send payload to 101
2015-03-10 12:37:38.755785 [DEBUG] switch_core_media.c:5445 Set 2833
dtmf receive payload to 101
2015-03-10 12:37:38.755785 [NOTICE] sofia_media.c:92 Pre-Answer
sofia/internal/1001@freeswitch.xyz.com.au!
2015-03-10 12:37:38.755785 [DEBUG] switch_channel.c:3399
(sofia/internal/1001@freeswitch.xyz.com.au) Callstate Change RINGING ->
EARLY
2015-03-10 12:37:38.755785 [DEBUG] mod_sofia.c:780 Local SDP
sofia/internal/1001@freeswitch.xyz.com.au:
v=0
o=FreeSWITCH 1425930696 1425930697 IN IP4 10.0.2.145
s=FreeSWITCH
c=IN IP4 10.0.2.145
t=0 0
m=audio 20762 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2015-03-10 12:37:38.755785 [DEBUG] switch_core_session.c:908 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.755785 [NOTICE] switch_ivr_originate.c:3522 Channel
[sofia/internal/1001@freeswitch.xyz.com.au] has been answered
2015-03-10 12:37:38.755785 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.755785 [DEBUG] switch_channel.c:3689
(sofia/internal/1001@freeswitch.xyz.com.au) Callstate Change EARLY -> ACTIVE
2015-03-10 12:37:38.755785 [DEBUG] sofia.c:6614 Channel
sofia/internal/1001@freeswitch.xyz.com.au entering state [completed][200]
2015-03-10 12:37:38.755785 [DEBUG] switch_ivr_originate.c:3580 Originate
Resulted in Success: [sofia/external/775]
2015-03-10 12:37:38.755785 [DEBUG] switch_core_session.c:908 Send signal
sofia/external/775 [BREAK]
2015-03-10 12:37:38.755785 [DEBUG] switch_core_session.c:908 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.755785 [DEBUG] switch_ivr_bridge.c:1465
(sofia/external/775) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2015-03-10 12:37:38.755785 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:38.755785 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_EXCHANGE_MEDIA
2015-03-10 12:37:38.755785 [DEBUG] switch_core_state_machine.c:538
(sofia/external/775) State EXCHANGE_MEDIA
2015-03-10 12:37:38.755785 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA
2015-03-10 12:37:38.795788 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.795788 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.795788 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.795788 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6663 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:38.815813 [DEBUG] sofia.c:6614 Channel
sofia/internal/1001@freeswitch.xyz.com.au entering state [ready][200]
2015-03-10 12:37:38.815813 [DEBUG] switch_core_session.c:970 Send signal
sofia/external/775 [BREAK]
2015-03-10 12:37:38.815813 [DEBUG] switch_core_session.c:970 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.815813 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16178 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:38.835797 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.835797 [DEBUG] sofia.c:6614 Channel
sofia/internal/1001@freeswitch.xyz.com.au entering state [calling][0]
2015-03-10 12:37:38.895793 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6664 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:38.915789 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16179 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:38.935794 [DEBUG] switch_rtp.c:5853 Correct ip/port
confirmed.
2015-03-10 12:37:38.935794 [NOTICE] switch_core_io.c:1261 Activating
write resampler
2015-03-10 12:37:38.935794 [INFO] mod_com_g729.c:126 ENCODER LICENSE
ALLOCATED--->0x7fc5640abbf0 0x7fc5640abbf0
2015-03-10 12:37:38.935794 [INFO] mod_com_g729.c:133 ENCODER
CREATED------------->0x7fc5640abbf0 0x7fc5640abbf0
2015-03-10 12:37:38.935794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.935794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.935794 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:38.955811 [DEBUG] sofia.c:6614 Channel
sofia/internal/1001@freeswitch.xyz.com.au entering state [ready][200]
2015-03-10 12:37:38.955811 [DEBUG] sofia.c:6624 Remote SDP:
v=0
o=- 20183 20184 IN IP4 10.0.2.129
s=SDP data
c=IN IP4 10.0.2.129
t=0 0
a=sendrecv
m=audio 11794 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3682 Audio Codec
Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3627 Audio Codec
Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3543 Set
telephone-event payload to 101
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:3890 Set 2833
dtmf send/recv payload to 101
2015-03-10 12:37:38.955811 [DEBUG] sofia.c:7318 Processing updated SDP
2015-03-10 12:37:38.955811 [DEBUG] switch_core_media.c:5124 Audio params
are unchanged for sofia/internal/1001@freeswitch.xyz.com.au.
2015-03-10 12:37:39.095797 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6665 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:39.115795 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16180 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:39.295792 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6666 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:39.315799 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16181 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:39.495820 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
WARNING! HELLO have been resent 5 times without a response. Raising
ZRTP_EVENT_NO_ZRTP_QUICK event. ID=61
2015-03-10 12:37:39.495820 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6667 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:39.515800 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
WARNING! HELLO have been resent 5 times without a response. Raising
ZRTP_EVENT_NO_ZRTP_QUICK event. ID=62
2015-03-10 12:37:39.515800 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16182 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:39.635793 [DEBUG] switch_rtp.c:5853 Correct ip/port
confirmed.
2015-03-10 12:37:39.635793 [INFO] mod_com_g729.c:164 DECODER LICENSE
ALLOCATED--->0x7fc5640abb70 0x7fc5640abb78
2015-03-10 12:37:39.635793 [INFO] mod_com_g729.c:171 DECODER
CREATED------------->0x7fc5640abb70 0x7fc5640abb78
2015-03-10 12:37:39.635793 [NOTICE] switch_core_io.c:1261 Activating
write resampler
2015-03-10 12:37:39.695794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6668 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:39.715818 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16183 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:39.895794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6669 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:39.915788 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16184 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:40.095795 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6670 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:40.115797 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16185 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:40.295795 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6671 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:40.315799 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16186 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:40.495794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6672 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:40.515796 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16187 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:40.695794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6673 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:40.715793 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16188 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:40.895795 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6674 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:40.915814 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16189 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:41.095793 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6675 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:41.115793 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16190 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:41.295810 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6676 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:41.315792 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16191 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:41.495802 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6677 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:41.515827 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16192 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:41.695792 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6678 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:41.715791 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16193 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:41.895794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6679 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:41.915786 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16194 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:42.095794 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6680 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:42.115792 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16195 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:42.295796 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=2970911498 seq=6681 size=144. Stream 61:CLEAR:START
2015-03-10 12:37:42.315793 [DEBUG] switch_rtp.c:1357  [  zrtp utils]:  
Send <HELLO> ssrc=1447443834 seq=16196 size=144. Stream 62:CLEAR:START
2015-03-10 12:37:42.495796 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
WARNING! HELLO Max retransmissions count reached (20 retries). ID=61
2015-03-10 12:37:42.495796 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=61 CLEAR switching <START> ---> <NOZRTP>.
2015-03-10 12:37:42.515800 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
WARNING! HELLO Max retransmissions count reached (20 retries). ID=62
2015-03-10 12:37:42.515800 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=62 CLEAR switching <START> ---> <NOZRTP>.
2015-03-10 12:37:43.675790 [DEBUG] switch_core_session.c:1053 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:43.695793 [NOTICE] sofia.c:952 Hangup
sofia/internal/1001@freeswitch.xyz.com.au [CS_EXECUTE] [NORMAL_CLEARING]
2015-03-10 12:37:43.695793 [DEBUG] switch_channel.c:3222 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [KILL]
2015-03-10 12:37:43.695793 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:43.695793 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD
DONE [sofia/internal/1001@freeswitch.xyz.com.au]
2015-03-10 12:37:43.695793 [DEBUG] switch_ivr_bridge.c:690 Send signal
sofia/external/775 [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_ivr_bridge.c:579
sofia/internal/1001@freeswitch.xyz.com.au ending bridge by request from
write function
2015-03-10 12:37:43.715797 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD
DONE [sofia/external/775]
2015-03-10 12:37:43.715797 [DEBUG] switch_ivr_bridge.c:690 Send signal
sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:43.715797 [NOTICE] switch_ivr_bridge.c:754 Hangup
sofia/external/775 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2015-03-10 12:37:43.715797 [DEBUG] switch_channel.c:3222 Send signal
sofia/external/775 [KILL]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:538
(sofia/external/775) State EXCHANGE_MEDIA going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_HANGUP
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:735
(sofia/external/775) Callstate Change ACTIVE -> HANGUP
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:737
(sofia/external/775) State HANGUP
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:407 sofia/external/775
Overriding SIP cause 480 with 200 from the other leg
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:413 Channel
sofia/external/775 hanging up, cause: NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:465 Sending BYE to
sofia/external/775
2015-03-10 12:37:43.715797 [DEBUG] switch_ivr_bridge.c:1563
sofia/external/775 skip receive message [UNBRIDGE] (channel is hungup
already)
2015-03-10 12:37:43.715797 [DEBUG] switch_ivr_bridge.c:1566
sofia/internal/1001@freeswitch.xyz.com.au skip receive message
[UNBRIDGE] (channel is hungup already)
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:60
sofia/external/775 Standard HANGUP, cause: NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:737
(sofia/external/775) State HANGUP going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:504
(sofia/external/775) State Change CS_HANGUP -> CS_REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:2893
sofia/internal/1001@freeswitch.xyz.com.au skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:472
(sofia/external/775) Running State Change CS_REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:535
(sofia/internal/1001@freeswitch.xyz.com.au) State EXECUTE going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_HANGUP
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:823
(sofia/external/775) State REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:104
sofia/external/775 Standard REPORTING, cause: NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:823
(sofia/external/775) State REPORTING going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:735
(sofia/internal/1001@freeswitch.xyz.com.au) Callstate Change ACTIVE ->
HANGUP
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:737
(sofia/internal/1001@freeswitch.xyz.com.au) State HANGUP
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:498
(sofia/external/775) State Change CS_REPORTING -> CS_DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1388 Send
signal sofia/external/775 [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1615 Session 66
(sofia/external/775) Locked, Waiting on external entities
2015-03-10 12:37:43.715797 [NOTICE] switch_core_session.c:1633 Session
66 (sofia/external/775) Ended
2015-03-10 12:37:43.715797 [NOTICE] switch_core_session.c:1637 Close
Channel sofia/external/775 [CS_DESTROY]
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:413 Channel
sofia/internal/1001@freeswitch.xyz.com.au hanging up, cause: NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:626
(sofia/external/775) Running State Change CS_DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:636
(sofia/external/775) State DESTROY
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:323 sofia/external/775
SOFIA DESTROY
2015-03-10 12:37:43.715797 [INFO] mod_com_g729.c:95 DECODER
DESTROYED----------->0x7fc5640abb70 0x7fc5640abb78
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:60
sofia/internal/1001@freeswitch.xyz.com.au Standard HANGUP, cause:
NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:737
(sofia/internal/1001@freeswitch.xyz.com.au) State HANGUP going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:504
(sofia/internal/1001@freeswitch.xyz.com.au) State Change CS_HANGUP ->
CS_REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:472
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change
CS_REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:823
(sofia/internal/1001@freeswitch.xyz.com.au) State REPORTING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:104
sofia/internal/1001@freeswitch.xyz.com.au Standard REPORTING, cause:
NORMAL_CLEARING
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:823
(sofia/internal/1001@freeswitch.xyz.com.au) State REPORTING going to sleep
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:498
(sofia/internal/1001@freeswitch.xyz.com.au) State Change CS_REPORTING ->
CS_DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1388 Send
signal sofia/internal/1001@freeswitch.xyz.com.au [BREAK]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_session.c:1615 Session 65
(sofia/internal/1001@freeswitch.xyz.com.au) Locked, Waiting on external
entities
2015-03-10 12:37:43.715797 [NOTICE] switch_core_session.c:1633 Session
65 (sofia/internal/1001@freeswitch.xyz.com.au) Ended
2015-03-10 12:37:43.715797 [NOTICE] switch_core_session.c:1637 Close
Channel sofia/internal/1001@freeswitch.xyz.com.au [CS_DESTROY]
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:626
(sofia/internal/1001@freeswitch.xyz.com.au) Running State Change CS_DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:636
(sofia/internal/1001@freeswitch.xyz.com.au) State DESTROY
2015-03-10 12:37:43.715797 [DEBUG] mod_sofia.c:323
sofia/internal/1001@freeswitch.xyz.com.au SOFIA DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=62 mode=CLEAR state=NOZRTP.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:111
sofia/internal/1001@freeswitch.xyz.com.au Standard DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:636
(sofia/internal/1001@freeswitch.xyz.com.au) State DESTROY going to sleep
2015-03-10 12:37:43.715797 [INFO] mod_com_g729.c:98 DECODER LICENSE
DEALLOCATED->0x7fc5640abb70 0x7fc5640abb78
2015-03-10 12:37:43.715797 [INFO] mod_com_g729.c:84 ENCODER
DESTROYED----------->0x7fc5640abbf0 0x7fc5640abbf0
2015-03-10 12:37:43.715797 [INFO] mod_com_g729.c:87 ENCODER LICENSE
DEALLOCATED->0x7fc5640abbf0 0x7fc5640abbf0
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=61 mode=CLEAR state=NOZRTP.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [        zrtp]:  
Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-03-10 12:37:43.715797 [DEBUG] switch_rtp.c:1357  [ zrtp engine]:
STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:111
sofia/external/775 Standard DESTROY
2015-03-10 12:37:43.715797 [DEBUG] switch_core_state_machine.c:636
(sofia/external/775) State DESTROY going to sleep

-- 
Jason Lewis
http://emacstragic.net