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@192.168.10.30 [66610a8c-aec9-48ca-9b67-aafdcd3e3d08]
2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3727 Channel sofia/internal/60002@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@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@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@192.168.10.30 [BREAK]
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@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@192.168.10.30) State INIT
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:83 sofia/internal/60002@192.168.10.30 SOFIA INIT
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:111 (sofia/internal/60002@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@192.168.10.30 [BREAK]
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/60002@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@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@192.168.10.30) State ROUTING
2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:132 sofia/internal/60002@192.168.10.30 SOFIA ROUTING
2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:78 sofia/internal/60002@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@192.168.10.30 parsing [default->unloop] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [tod_example] ${strftime(%w)}(2) =~ /^([1-5])$/ break=on-false
Dialplan: sofia/internal/60002@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@192.168.10.30 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^\*886$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->redial] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [redial] destination_number(1001) =~ /^\*870$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->global] continue=true
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${network_addr}(192.168.10.131) =~ /^$/ break=never
Dialplan: sofia/internal/60002@192.168.10.30 ANTI-Action set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat : default)})
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [global] ${numbering_plan}() =~ /^$/ break=never
Dialplan: sofia/internal/60002@192.168.10.30 Action set_user(default@${domain_name})
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/60002@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@192.168.10.30 Absolute Condition [global]
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^\*9001$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^\*9000$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*88(.*)$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*779$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_privacy] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_privacy] destination_number(1001) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_return] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->del-group] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [del-group] destination_number(1001) =~ /^\*80(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->add-group] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [add-group] destination_number(1001) =~ /^\*81(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^\*82(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^\*83(\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^\*8(\d{4})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_5digits] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_5digits] destination_number(1001) =~ /^\*99(\d{5})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_4digits] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_4digits] destination_number(1001) =~ /^\*99(\d{4})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_3digits] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_3digits] destination_number(1001) =~ /^\*99(\d{3})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->2001] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [2001] destination_number(1001) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Call via asterisk-pbx1] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Call via asterisk-pbx1] destination_number(1001) =~ /269065/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->5002] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [5002] destination_number(1001) =~ /^5002$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002] destination_number(1001) =~ /^7002$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->DISA] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [DISA] destination_number(1001) =~ /^\*(3472)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Recordings] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Recordings] destination_number(1001) =~ /^\*(732673)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002.park] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002.park] destination_number(1001) =~ /^\*7002$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_sales] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_sales] destination_number(1001) =~ /^\*2000$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_support] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_support] destination_number(1001) =~ /^\*2001$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_billing] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_billing] destination_number(1001) =~ /^\*2002$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain2] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain2] destination_number(1001) =~ /^vmain2$|^\*97$|^\*4000$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain] destination_number(1001) =~ /^vmain$|^\*98$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->sip_uri] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [sip_uri] destination_number(1001) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->nb_conferences] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [nb_conferences] destination_number(1001) =~ /^\*(30\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wb_conferences] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wb_conferences] destination_number(1001) =~ /^\*(31\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->uwb_conferences] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [uwb_conferences] destination_number(1001) =~ /^\*(32\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [cdquality_conferences] destination_number(1001) =~ /^\*(33\d{2})$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/60002@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@192.168.10.30 parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0911$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0912$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss] destination_number(1001) =~ /^\*0913$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ivr_demo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ivr_demo] destination_number(1001) =~ /^\*5000$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->dynamic_conference] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [dynamic_conference] destination_number(1001) =~ /^\*5001$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->rtp_multicast_page] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [rtp_multicast_page] destination_number(1001) =~ /^\*pagegroup$|^\*7243/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /^\*5900$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^\*5901$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^parking$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /callpark/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /pickup/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wait] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wait] destination_number(1001) =~ /^wait$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_receive] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_receive] destination_number(1001) =~ /^\*9978$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_transmit] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_transmit] destination_number(1001) =~ /^\*9979$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_180] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_180] destination_number(1001) =~ /^\*9980$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_uk_ring] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_uk_ring] destination_number(1001) =~ /^\*9981$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_music_ring] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_music_ring] destination_number(1001) =~ /^\*9982$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(1001) =~ /^\*9983$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_music] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_music] destination_number(1001) =~ /^\*9984$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ClueCon] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ClueCon] destination_number(1001) =~ /^\*9991$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->show_info] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [show_info] destination_number(1001) =~ /^\*9992$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_record] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_record] destination_number(1001) =~ /^\*9993$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_playback] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_playback] destination_number(1001) =~ /^\*9994$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->delay_echo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [delay_echo] destination_number(1001) =~ /^\*9995$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->echo] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [echo] destination_number(1001) =~ /^\*9996$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->milliwatt] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [milliwatt] destination_number(1001) =~ /^\*9997$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tone_stream] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [tone_stream] destination_number(1001) =~ /^\*9998$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->zrtp_enrollement] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [zrtp_enrollement] destination_number(1001) =~ /^\*9787$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->hold_music] continue=false
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [hold_music] destination_number(1001) =~ /^\*9999$/ break=on-false
Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/60002@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@192.168.10.30 Action set(dialed_extension=1001)
Dialplan: sofia/internal/60002@192.168.10.30 Action export(dialed_extension=1001)
Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/60002@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@192.168.10.30 Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/60002@192.168.10.30 Action set(ringback=${us-ring})
Dialplan: sofia/internal/60002@192.168.10.30 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/60002@192.168.10.30 Action set(call_timeout=30)
Dialplan: sofia/internal/60002@192.168.10.30 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/60002@192.168.10.30 Action set(continue_on_fail=true)
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/60002@192.168.10.30 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/60002@192.168.10.30 Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/60002@192.168.10.30 Action answer()
Dialplan: sofia/internal/60002@192.168.10.30 Action sleep(1000)
Dialplan: sofia/internal/60002@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@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@192.168.10.30 [BREAK]
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/60002@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@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@192.168.10.30) State EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] mod_sofia.c:181 sofia/internal/60002@192.168.10.30 SOFIA EXECUTE
2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:159 sofia/internal/60002@192.168.10.30 Standard EXECUTE
EXECUTE sofia/internal/60002@192.168.10.30 set(use_profile=default)
2010-02-09 21:49:32.798073 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [use_profile]=[default]
EXECUTE sofia/internal/60002@192.168.10.30 set_user(default@192.168.10.30)
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-spymap/60002/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-last_dial/60002/1001)
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-last_dial/global/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002@192.168.10.30 set(dialed_extension=1001)
2010-02-09 21:49:32.857126 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [dialed_extension]=[1001]
EXECUTE sofia/internal/60002@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@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@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@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@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@192.168.10.30 SET [ringback]=[%(2000, 4000, 440.0, 480.0)]
EXECUTE sofia/internal/60002@192.168.10.30 set(transfer_ringback=local_stream://moh)
2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/60002@192.168.10.30 set(call_timeout=30)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [call_timeout]=[30]
EXECUTE sofia/internal/60002@192.168.10.30 set(hangup_after_bridge=true)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/60002@192.168.10.30 set(continue_on_fail=true)
2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-call_return/1001/60002)
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-last_dial_ext/1001/66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002@192.168.10.30 set(called_party_callgroup=)
2010-02-09 21:49:32.870074 [DEBUG] mod_dptools.c:768 sofia/internal/60002@192.168.10.30 SET [called_party_callgroup]=[UNDEF]
EXECUTE sofia/internal/60002@192.168.10.30 db(insert/192.168.10.30-last_dial//66610a8c-aec9-48ca-9b67-aafdcd3e3d08)
EXECUTE sofia/internal/60002@192.168.10.30 bridge(user/1001@192.168.10.30)
2010-02-09 21:49:32.905073 [DEBUG] switch_ivr_originate.c:1735 variable string 0 = [presence_id=1001@192.168.10.30]
2010-02-09 21:49:32.905073 [NOTICE] switch_channel.c:613 New Channel sofia/internal/sip:1001@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@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@192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@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@192.168.10.192:41080) State INIT
2010-02-09 21:49:32.906075 [DEBUG] mod_sofia.c:83 sofia/internal/sip:1001@192.168.10.192:41080 SOFIA INIT
2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:111 (sofia/internal/sip:1001@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@192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.907184 [DEBUG] sofia.c:3727 Channel sofia/internal/sip:1001@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@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@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@192.168.10.192:41080) State ROUTING
2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:132 sofia/internal/sip:1001@192.168.10.192:41080 SOFIA ROUTING
2010-02-09 21:49:32.907184 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@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@192.168.10.192:41080 [BREAK]
2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1001@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@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@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@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@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@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@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@192.168.10.192:41080 [BREAK]
2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:459 sofia/internal/sip:1001@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@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@192.168.10.192:41080) State HANGUP
2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:352 sofia/internal/sip:1001@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@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@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@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@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@192.168.10.192:41080 [BREAK]
2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@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@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@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@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@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@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@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@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@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@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@192.168.10.192:41080) State DESTROY
2010-02-09 21:49:33.331072 [DEBUG] mod_sofia.c:293 sofia/internal/sip:1001@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@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@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@192.168.10.30 answer()
2010-02-09 21:49:33.332075 [DEBUG] mod_dptools.c:658 sofia/internal/60002@192.168.10.30 receive message [ANSWER]
2010-02-09 21:49:33.332075 [DEBUG] sofia_glue.c:2381 AUDIO RTP [sofia/internal/60002@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@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@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@192.168.10.30 [BREAK]
2010-02-09 21:49:33.333080 [NOTICE] mod_dptools.c:658 Channel [sofia/internal/60002@192.168.10.30] has been answered
2010-02-09 21:49:33.333080 [DEBUG] switch_channel.c:182 sofia/internal/60002@192.168.10.30 receive message [AUDIO_SYNC]
EXECUTE sofia/internal/60002@192.168.10.30 sleep(1000)
2010-02-09 21:49:33.334081 [DEBUG] switch_channel.c:182 sofia/internal/60002@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@192.168.10.30 entering state [ready][200]
EXECUTE sofia/internal/60002@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@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@16000hz 1 channels 20ms
2010-02-09 21:49:34.526072 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:36.028065 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:36.461074 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:36.995060 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:37.535061 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:38.120062 [DEBUG] switch_core_io.c:652 sofia/internal/60002@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@16000hz 1 channels 20ms
2010-02-09 21:49:39.192068 [DEBUG] switch_core_io.c:652 sofia/internal/60002@192.168.10.30 receive message [TRANSCODING_NECESSARY]
2010-02-09 21:49:40.999151 [NOTICE] sofia.c:329 Hangup sofia/internal/60002@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@192.168.10.30 [KILL]
2010-02-09 21:49:40.999151 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK]
2010-02-09 21:49:40.999151 [DEBUG] switch_core_state_machine.c:459 sofia/internal/60002@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@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@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@192.168.10.30) State HANGUP
2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:352 sofia/internal/60002@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@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@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@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@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@192.168.10.30 [BREAK]
2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@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@192.168.10.30) State REPORTING
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:53 sofia/internal/60002@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@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@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@192.168.10.30 [BREAK]
2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:1136 Session 1 (sofia/internal/60002@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@192.168.10.30) Ended
2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1156 Close Channel sofia/internal/60002@192.168.10.30 [CS_DESTROY]
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/60002@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@192.168.10.30) State DESTROY
2010-02-09 21:49:41.129049 [DEBUG] mod_sofia.c:293 sofia/internal/60002@192.168.10.30 SOFIA DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:60 sofia/internal/60002@192.168.10.30 Standard DESTROY
2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/60002@192.168.10.30) State DESTROY going to sleep






On 9 February 2010 21:18, Brian West <brian@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@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org