[Freeswitch-users] g.722 --> SPEEX/16000 or SPEEX/32000 transcoding issue

Tue Feb 9 13:55:13 PST 2010

Willdo,

To clarify in brief though, the scenario which occurs and causes the call to
fail is:

SIP client  1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media
Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH

---> INVITE (with SDP offer including a bunch of codecs including rtpmap:
rtpmap:98 SPEEX/8000 but crucially *not* including SPEEX/16000 or
SPEEX/32000)

---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled).

The second SIP client does not get offered a codec it can accept, so SIP
client 1 is sent a method 488 "Not Acceptable Here" message and the calling
party gets directed to the voicemail for the other SIP client.

By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or
calling SPEEX/16000 --> SPEEX/16000.

there is also no problem calling SPEEX/32000 --> g.722/8000.

I am wondering if the problem is that FreeSWITCH is interpreting g.722 as
being a narrowband (8kHz sample rate) codec, due to the historic anomaly of
it presenting g722/8000 in the SDP even though it in fact uses 16kHz
sampling, and for that reason not wanting to offer a 16kHz sample rate codec
to the second SIP client?

I suggest this as I also found trying to call alaw --> SPEEX/16000 does not
work, for example.

Here is the log file for the scenario which does not work (g.722 client
trying to call Speex wideband client).  Please let me know if a Wireshark
trace would be helpful.

2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5224 0 acls to check for proxy
2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5242 network ip is a proxy [0]
2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected
by acl "domains". Falling back to Digest auth.
2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5224 0 acls to check for proxy
2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5242 network ip is a proxy [0]
2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected
by acl "domains". Falling back to Digest auth.
2010-02-09 21:49:32.794074 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/60002 at 192.168.10.30 [66610a8c-aec9-48ca-9b67-aafdcd3e3d08]
2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3727 Channel sofia/internal/
60002 at 192.168.10.30 entering state [received][100]
2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3738 Remote SDP:
v=0
o=- 5 2 IN IP4 192.168.10.131
s=CounterPath eyeBeam 1.5
c=IN IP4 192.168.10.131
t=0 0
m=audio 25592 RTP/AVP 9 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2010-02-09 21:49:32.794074 [DEBUG] sofia_glue.c:3305 Audio Codec Compare
[G722:9:8000:20]/[G722:9:8000:20]
2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:2143 Set Codec
sofia/internal/60002 at 192.168.10.30 G722/8000 20 ms 160 samples
2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:3261 Set 2833 dtmf payload
to 101
2010-02-09 21:49:32.795079 [DEBUG] sofia.c:3885 (sofia/internal/
60002 at 192.168.10.30) State Change CS_NEW -> CS_INIT
2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_INIT
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/60002 at 192.168.10.30) State INIT
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:83 sofia/internal/
60002 at 192.168.10.30 SOFIA INIT
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:111 (sofia/internal/
60002 at 192.168.10.30) State Change CS_INIT -> CS_ROUTING
2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/60002 at 192.168.10.30) State INIT going to sleep
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_ROUTING
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/60002 at 192.168.10.30) State ROUTING
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:132 sofia/internal/
60002 at 192.168.10.30 SOFIA ROUTING
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:78
sofia/internal/60002 at 192.168.10.30 Standard ROUTING
2010-02-09 21:49:32.795079 [INFO] mod_dialplan_xml.c:408 Processing
60002->1001 in context default
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->unloop]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->tod_example]
continue=true
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [tod_example]
${strftime(%w)}(2) =~ /^([1-5])$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [tod_example]
${strftime(%H%M)}(2149) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [global-intercept]
destination_number(1001) =~ /^\*886$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [group-intercept]
destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [intercept-ext]
destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->redial]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [redial]
destination_number(1001) =~ /^\*870$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->global]
continue=true
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [global]
${network_addr}(192.168.10.131) =~ /^$/ break=never
Dialplan: sofia/internal/60002 at 192.168.10.30 ANTI-Action
set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat :
default)})
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [global]
${numbering_plan}() =~ /^$/ break=never
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set_user(default@${domain_name})

Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [global]
${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
break=never
Dialplan: sofia/internal/60002 at 192.168.10.30 Absolute Condition [global]
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})

Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->snom-demo-2]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [snom-demo-2]
destination_number(1001) =~ /^\*9001$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->snom-demo-1]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [snom-demo-1]
destination_number(1001) =~ /^\*9000$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^\*88(.*)$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^\*779$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->call_privacy]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [call_privacy]
destination_number(1001) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->call_return]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [call_return]
destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->del-group]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [del-group]
destination_number(1001) =~ /^\*80(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->add-group]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [add-group]
destination_number(1001) =~ /^\*81(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [call-group-simo]
destination_number(1001) =~ /^\*82(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [call-group-order]
destination_number(1001) =~ /^\*83(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[extension-intercom] destination_number(1001) =~ /^\*8(\d{4})$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->send_to_voicemail_5digits] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[send_to_voicemail_5digits] destination_number(1001) =~ /^\*99(\d{5})$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->send_to_voicemail_4digits] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[send_to_voicemail_4digits] destination_number(1001) =~ /^\*99(\d{4})$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->send_to_voicemail_3digits] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[send_to_voicemail_3digits] destination_number(1001) =~ /^\*99(\d{3})$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->pizza_demo]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [pizza_demo]
destination_number(1001) =~ /^(pizza|74992)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->2001]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [2001]
destination_number(1001) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->Call via
asterisk-pbx1] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [Call via
asterisk-pbx1] destination_number(1001) =~ /269065/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->pizza_demo]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [pizza_demo]
destination_number(1001) =~ /^(pizza|74992)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->5002]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [5002]
destination_number(1001) =~ /^5002$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->7002]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [7002]
destination_number(1001) =~ /^7002$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->DISA]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [DISA]
destination_number(1001) =~ /^\*(3472)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->Recordings]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [Recordings]
destination_number(1001) =~ /^\*(732673)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->7002.park]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [7002.park]
destination_number(1001) =~ /^\*7002$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->group_dial_sales] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [group_dial_sales]
destination_number(1001) =~ /^\*2000$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->group_dial_support] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[group_dial_support] destination_number(1001) =~ /^\*2001$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->group_dial_billing] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[group_dial_billing] destination_number(1001) =~ /^\*2002$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->vmain2]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [vmain2]
destination_number(1001) =~ /^vmain2$|^\*97$|^\*4000$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->vmain]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [vmain]
destination_number(1001) =~ /^vmain$|^\*98$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->sip_uri]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [sip_uri]
destination_number(1001) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->nb_conferences] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [nb_conferences]
destination_number(1001) =~ /^\*(30\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->wb_conferences] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [wb_conferences]
destination_number(1001) =~ /^\*(31\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->uwb_conferences] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [uwb_conferences]
destination_number(1001) =~ /^\*(32\d{2})$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->cdquality_conferences] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[cdquality_conferences] destination_number(1001) =~ /^\*(33\d{2})$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[freeswitch_public_conf_via_sip] destination_number(1001) =~
/^\*9(888|1616|3232)$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[mad_boss_intercom] destination_number(1001) =~ /^\*0911$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[mad_boss_intercom] destination_number(1001) =~ /^\*0912$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->mad_boss]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [mad_boss]
destination_number(1001) =~ /^\*0913$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->ivr_demo]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [ivr_demo]
destination_number(1001) =~ /^\*5000$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->dynamic_conference] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[dynamic_conference] destination_number(1001) =~ /^\*5001$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->rtp_multicast_page] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[rtp_multicast_page] destination_number(1001) =~ /^\*pagegroup$|^\*7243/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->park]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [park]
destination_number(1001) =~ /^\*5900$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [unpark]
destination_number(1001) =~ /^\*5901$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->park]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [park]
destination_number(1001) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [unpark]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [unpark]
destination_number(1001) =~ /^parking$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->park]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [park]
destination_number(1001) =~ /callpark/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [unpark]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [unpark]
destination_number(1001) =~ /pickup/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->wait]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [wait]
destination_number(1001) =~ /^wait$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->fax_receive]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [fax_receive]
destination_number(1001) =~ /^\*9978$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->fax_transmit]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [fax_transmit]
destination_number(1001) =~ /^\*9979$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->ringback_180]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [ringback_180]
destination_number(1001) =~ /^\*9980$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->ringback_183_uk_ring] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[ringback_183_uk_ring] destination_number(1001) =~ /^\*9981$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->ringback_183_music_ring] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[ringback_183_music_ring] destination_number(1001) =~ /^\*9982$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[ringback_post_answer_uk_ring] destination_number(1001) =~ /^\*9983$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->ringback_post_answer_music] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL)
[ringback_post_answer_music] destination_number(1001) =~ /^\*9984$/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->ClueCon]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [ClueCon]
destination_number(1001) =~ /^\*9991$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->show_info]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [show_info]
destination_number(1001) =~ /^\*9992$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->video_record]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [video_record]
destination_number(1001) =~ /^\*9993$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->video_playback] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [video_playback]
destination_number(1001) =~ /^\*9994$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->delay_echo]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [delay_echo]
destination_number(1001) =~ /^\*9995$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->echo]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [echo]
destination_number(1001) =~ /^\*9996$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->milliwatt]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [milliwatt]
destination_number(1001) =~ /^\*9997$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->tone_stream]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [tone_stream]
destination_number(1001) =~ /^\*9998$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->zrtp_enrollement] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [zrtp_enrollement]
destination_number(1001) =~ /^\*9787$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing [default->hold_music]
continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (FAIL) [hold_music]
destination_number(1001) =~ /^\*9999$/ break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/60002 at 192.168.10.30 Regex (PASS) [Local_Extension]
destination_number(1001) =~ /(^\d{6}$|\d{5}$|^\d{4}$|^\d{3}$)/
break=on-false
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set(dialed_extension=1001)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
export(dialed_extension=1001)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)

Dialplan: sofia/internal/60002 at 192.168.10.30 Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action set(ringback=${us-ring})

Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action set(call_timeout=30)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set(continue_on_fail=true)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})

Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/60002 at 192.168.10.30 Action
bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/60002 at 192.168.10.30 Action answer()
Dialplan: sofia/internal/60002 at 192.168.10.30 Action sleep(1000)
Dialplan: sofia/internal/60002 at 192.168.10.30 Action voicemail(default
${domain_name} ${dialed_extension})
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:122
(sofia/internal/60002 at 192.168.10.30) State Change CS_ROUTING -> CS_EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/60002 at 192.168.10.30) State ROUTING going to sleep
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/60002 at 192.168.10.30) State EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] mod_sofia.c:181 sofia/internal/
60002 at 192.168.10.30 SOFIA EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:159
sofia/internal/60002 at 192.168.10.30 Standard EXECUTE
EXECUTE sofia/internal/60002 at 192.168.10.30 set(use_profile=default)
2010-02-09 21:49:32.798073 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [use_profile]=[default]
EXECUTE sofia/internal/60002 at 192.168.10.30 set_user(default at 192.168.10.30)
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-spymap/60002/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-last_dial/60002/1001)
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-last_dial/global/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002 at 192.168.10.30 set(dialed_extension=1001)
2010-02-09 21:49:32.857126 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [dialed_extension]=[1001]
EXECUTE sofia/internal/60002 at 192.168.10.30 export(dialed_extension=1001)
2010-02-09 21:49:32.858075 [DEBUG] mod_dptools.c:851 EXPORT
[dialed_extension]=[1001]
EXECUTE sofia/internal/60002 at 192.168.10.30 bind_meta_app(1 b s
execute_extension::dx XML features)
2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 1
execute_extension::dx XML features
EXECUTE sofia/internal/60002 at 192.168.10.30 bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav)
2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 2
record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav
EXECUTE sofia/internal/60002 at 192.168.10.30 bind_meta_app(3 b s
execute_extension::cf XML features)
2010-02-09 21:49:32.859074 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 3
execute_extension::cf XML features
EXECUTE sofia/internal/60002 at 192.168.10.30 set(ringback=%(2000, 4000, 440.0,
480.0))
2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [ringback]=[%(2000, 4000, 440.0, 480.0)]
EXECUTE sofia/internal/60002 at 192.168.10.30set(transfer_ringback=local_stream://moh)
2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/60002 at 192.168.10.30 set(call_timeout=30)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [call_timeout]=[30]
EXECUTE sofia/internal/60002 at 192.168.10.30 set(hangup_after_bridge=true)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/60002 at 192.168.10.30 set(continue_on_fail=true)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-call_return/1001/60002)
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-last_dial_ext/1001/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002 at 192.168.10.30 set(called_party_callgroup=)
2010-02-09 21:49:32.870074 [DEBUG] mod_dptools.c:768 sofia/internal/
60002 at 192.168.10.30 SET [called_party_callgroup]=[UNDEF]
EXECUTE sofia/internal/60002 at 192.168.10.30db(insert/192.168.10.30-last_dial//66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002 at 192.168.10.30 bridge(user/1001 at 192.168.10.30)
2010-02-09 21:49:32.905073 [DEBUG] switch_ivr_originate.c:1735 variable
string 0 = [presence_id=1001 at 192.168.10.30]
2010-02-09 21:49:32.905073 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/sip:1001 at 192.168.10.192:41080[df7cf235-f0e4-406a-83a5-dd2d681bb278]
2010-02-09 21:49:32.905073 [DEBUG] mod_sofia.c:3142 (sofia/internal/
sip:1001 at 192.168.10.192:41080) State Change CS_NEW -> CS_INIT
2010-02-09 21:49:32.905073 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change CS_INIT
2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1001 at 192.168.10.192:41080) State INIT
2010-02-09 21:49:32.906075 [DEBUG] mod_sofia.c:83 sofia/internal/
sip:1001 at 192.168.10.192:41080 SOFIA INIT
2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:111 (sofia/internal/
sip:1001 at 192.168.10.192:41080) State Change CS_INIT -> CS_ROUTING
2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.907184 [DEBUG] sofia.c:3727 Channel sofia/internal/
sip:1001 at 192.168.10.192:41080 entering state [calling][0]
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:1001 at 192.168.10.192:41080) State INIT going to sleep
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change
CS_ROUTING
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1001 at 192.168.10.192:41080) State ROUTING
2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:132 sofia/internal/
sip:1001 at 192.168.10.192:41080 SOFIA ROUTING
2010-02-09 21:49:32.907184 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1001 at 192.168.10.192:41080) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:1001 at 192.168.10.192:41080) State ROUTING going to sleep
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change
CS_CONSUME_MEDIA
2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1001 at 192.168.10.192:41080) State CONSUME_MEDIA
2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:1001 at 192.168.10.192:41080) State CONSUME_MEDIA going to
sleep
2010-02-09 21:49:33.329319 [DEBUG] sofia.c:3727 Channel sofia/internal/
sip:1001 at 192.168.10.192:41080 entering state [terminated][488]
2010-02-09 21:49:33.329319 [NOTICE] sofia.c:4331 Hangup sofia/internal/
sip:1001 at 192.168.10.192:41080 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION]
2010-02-09 21:49:33.329319 [DEBUG] switch_channel.c:1912 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [KILL]
2010-02-09 21:49:33.329319 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:459
sofia/internal/sip:1001 at 192.168.10.192:41080 thread mismatch skipping state
handler.
2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change
CS_HANGUP
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/sip:1001 at 192.168.10.192:41080) State HANGUP
2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:352 sofia/internal/
sip:1001 at 192.168.10.192:41080 Overriding SIP cause 488 with 488 from the
other leg
2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:358 Channel sofia/internal/
sip:1001 at 192.168.10.192:41080 hanging up, cause: INCOMPATIBLE_DESTINATION
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:1001 at 192.168.10.192:41080 Standard HANGUP, cause:
INCOMPATIBLE_DESTINATION
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/sip:1001 at 192.168.10.192:41080) State HANGUP going to sleep
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1001 at 192.168.10.192:41080) State Change CS_HANGUP ->
CS_REPORTING
2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change
CS_REPORTING
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:1001 at 192.168.10.192:41080) State REPORTING
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:1001 at 192.168.10.192:41080 Standard REPORTING, cause:
INCOMPATIBLE_DESTINATION
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:1001 at 192.168.10.192:41080) State REPORTING going to
sleep
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/sip:1001 at 192.168.10.192:41080) State Change CS_REPORTING ->
CS_DESTROY
2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/sip:1001 at 192.168.10.192:41080 [BREAK]
2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:1136 Session 2
(sofia/internal/sip:1001 at 192.168.10.192:41080) Locked, Waiting on external
entities
2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate
Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1154 Session 2
(sofia/internal/sip:1001 at 192.168.10.192:41080) Ended
2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1156 Close Channel
sofia/internal/sip:1001 at 192.168.10.192:41080 [CS_DESTROY]
2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/sip:1001 at 192.168.10.192:41080) Running State Change
CS_DESTROY
2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/sip:1001 at 192.168.10.192:41080) State DESTROY
2010-02-09 21:49:33.331072 [DEBUG] mod_sofia.c:293 sofia/internal/
sip:1001 at 192.168.10.192:41080 SOFIA DESTROY
2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:1001 at 192.168.10.192:41080 Standard DESTROY
2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/sip:1001 at 192.168.10.192:41080) State DESTROY going to sleep
2010-02-09 21:49:33.331072 [ERR] switch_ivr_originate.c:2249 Cannot create
outgoing channel of type [user] cause: [INCOMPATIBLE_DESTINATION]
2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate
Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2010-02-09 21:49:33.331072 [INFO] mod_dptools.c:2294 Originate Failed.
Cause: INCOMPATIBLE_DESTINATION
EXECUTE sofia/internal/60002 at 192.168.10.30 answer()
2010-02-09 21:49:33.332075 [DEBUG] mod_dptools.c:658 sofia/internal/
60002 at 192.168.10.30 receive message [ANSWER]
2010-02-09 21:49:33.332075 [DEBUG] sofia_glue.c:2381 AUDIO RTP
[sofia/internal/60002 at 192.168.10.30] 192.168.10.30 port 27634 ->
192.168.10.131 port 25592 codec: 9 ms: 20
2010-02-09 21:49:33.332075 [DEBUG] switch_rtp.c:1167 Starting timer [soft]
160 bytes per 20ms
2010-02-09 21:49:33.333080 [DEBUG] mod_sofia.c:571 Local SDP sofia/internal/
60002 at 192.168.10.30:
v=0
o=FreeSWITCH 1265704739 1265704740 IN IP4 192.168.10.30
s=FreeSWITCH
c=IN IP4 192.168.10.30
t=0 0
m=audio 27634 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2010-02-09 21:49:33.333080 [DEBUG] sofia.c:3727 Channel sofia/internal/
60002 at 192.168.10.30 entering state [completed][200]
2010-02-09 21:49:33.333080 [DEBUG] switch_core_session.c:645 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:33.333080 [NOTICE] mod_dptools.c:658 Channel
[sofia/internal/60002 at 192.168.10.30] has been answered
2010-02-09 21:49:33.333080 [DEBUG] switch_channel.c:182 sofia/internal/
60002 at 192.168.10.30 receive message [AUDIO_SYNC]
EXECUTE sofia/internal/60002 at 192.168.10.30 sleep(1000)
2010-02-09 21:49:33.334081 [DEBUG] switch_channel.c:182 sofia/internal/
60002 at 192.168.10.30 receive message [AUDIO_SYNC]
2010-02-09 21:49:33.395069 [DEBUG] switch_rtp.c:2004 Correct ip/port
confirmed.
2010-02-09 21:49:33.455069 [DEBUG] sofia.c:3727 Channel sofia/internal/
60002 at 192.168.10.30 entering state [ready][200]
EXECUTE sofia/internal/60002 at 192.168.10.30 voicemail(default 192.168.10.30
1001)
2010-02-09 21:49:34.335070 [DEBUG] mod_voicemail.c:730 [default] rwlock
2010-02-09 21:49:34.370083 [DEBUG] switch_channel.c:182 sofia/internal/
60002 at 192.168.10.30 receive message [AUDIO_SYNC]
2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:118 No language
specified - Using [en]
2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:273 Handle
play-file:[voicemail/vm-person.wav] (en:en)
2010-02-09 21:49:34.523070 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:34.524073 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:34.526072 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:35.875063 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:35.995062 [DEBUG] switch_ivr_play_say.c:273 Handle
say:[1001] (en:en)
2010-02-09 21:49:36.027062 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:36.027062 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:36.028065 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:36.455072 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:36.460061 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:36.460061 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:36.461074 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:36.995060 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:36.995060 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:37.535061 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:37.535061 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:37.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:38.095060 [DEBUG] switch_ivr_play_say.c:273 Handle
play-file:[voicemail/vm-not_available.wav] (en:en)
2010-02-09 21:49:38.118060 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:38.119063 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:38.120062 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:39.075057 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:39.175057 [DEBUG] switch_ivr_play_say.c:118 No language
specified - Using [en]
2010-02-09 21:49:39.177086 [DEBUG] switch_ivr_play_say.c:273 Handle
play-file:[voicemail/vm-record_message.wav] (en:en)
2010-02-09 21:49:39.181967 [WARNING] switch_core_file.c:177 Sample rate
doesn't match
2010-02-09 21:49:39.181967 [DEBUG] switch_ivr_play_say.c:1154 Codec
Activated L16 at 16000hz 1 channels 20ms
2010-02-09 21:49:39.192068 [DEBUG] switch_core_io.c:652 sofia/internal/
60002 at 192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:40.999151 [NOTICE] sofia.c:329 Hangup sofia/internal/
60002 at 192.168.10.30 [CS_EXECUTE] [NORMAL_CLEARING]
2010-02-09 21:49:40.999151 [DEBUG] switch_channel.c:1912 Send signal
sofia/internal/60002 at 192.168.10.30 [KILL]
2010-02-09 21:49:40.999151 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:40.999151 [DEBUG] switch_core_state_machine.c:459
sofia/internal/60002 at 192.168.10.30 thread mismatch skipping state handler.
2010-02-09 21:49:41.015049 [DEBUG] switch_ivr_play_say.c:1446 done playing
file
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/60002 at 192.168.10.30) State EXECUTE going to sleep
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_HANGUP
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/60002 at 192.168.10.30) State HANGUP
2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:352 sofia/internal/
60002 at 192.168.10.30 Overriding SIP cause 480 with 488 from the other leg
2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:358 Channel sofia/internal/
60002 at 192.168.10.30 hanging up, cause: NORMAL_CLEARING
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:46
sofia/internal/60002 at 192.168.10.30 Standard HANGUP, cause: NORMAL_CLEARING
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488
(sofia/internal/60002 at 192.168.10.30) State HANGUP going to sleep
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/60002 at 192.168.10.30) State Change CS_HANGUP -> CS_REPORTING
2010-02-09 21:49:41.114049 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_REPORTING
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/60002 at 192.168.10.30) State REPORTING
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:53
sofia/internal/60002 at 192.168.10.30 Standard REPORTING, cause:
NORMAL_CLEARING
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/60002 at 192.168.10.30) State REPORTING going to sleep
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/60002 at 192.168.10.30) State Change CS_REPORTING -> CS_DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:999 Send signal
sofia/internal/60002 at 192.168.10.30 [BREAK]
2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:1136 Session 1
(sofia/internal/60002 at 192.168.10.30) Locked, Waiting on external entities
2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1154 Session 1
(sofia/internal/60002 at 192.168.10.30) Ended
2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1156 Close Channel
sofia/internal/60002 at 192.168.10.30 [CS_DESTROY]
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/60002 at 192.168.10.30) Running State Change CS_DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/60002 at 192.168.10.30) State DESTROY
2010-02-09 21:49:41.129049 [DEBUG] mod_sofia.c:293 sofia/internal/
60002 at 192.168.10.30 SOFIA DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:60
sofia/internal/60002 at 192.168.10.30 Standard DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/60002 at 192.168.10.30) State DESTROY going to sleep

On 9 February 2010 21:18, Brian West <brian at freeswitch.org> wrote:

> What you're saying makes little or no sense to me even on 1.0.4, Can you
> pastebin your logs?
>
> /b
>
> On Feb 9, 2010, at 3:15 PM, Bruce Hopkins wrote:
>
> > OK, many thanks for the extremely swift response Brian.
> >
> > I will try to get up and running as soon as I can with 1.0.5 and see if
> the issue goes away.
> >
> > thanks again
> > Bruce
>
>
> _______________________________________________
> 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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20100209/f036726e/attachment-0002.html 