<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><meta http-equiv=Content-Type content="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 15 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";
mso-fareast-language:EN-US;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri","sans-serif";
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri","sans-serif";
mso-fareast-language:EN-US;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-CA link="#0563C1" vlink="#954F72"><div class=WordSection1><p class=MsoNormal>In this example we are using 2 phones that are side by side ( same location) and trying to transfer the call from one to the other. <o:p></o:p></p><p class=MsoNormal>Here is the log , what I see is that the call (Ext 100) is transferred ( to 110) but when answered it is sent to voicemail. Do not know where or why it is being sent to voicemail. Any suggestion would be appreciated. It has to be a configuration error but I do not know where to look to fix it.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Regex (PASS) [local_extension] destination_number(110) =~ /(^\d{2,7}$)/ break=on-false<o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(dialed_extension=110) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action export(dialed_extension=110) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action limit(hash ${domain_name} 110 ${limit_max} ${limit_destination}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action bind_meta_app(1 b s execute_extension::dx XML features) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.wav) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action bind_meta_app(3 b s execute_extension::cf XML features) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(ringback=${us-ring}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(transfer_ringback=local_stream://moh) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(call_timeout=30) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(hangup_after_bridge=true) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(continue_on_fail=true) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action bridge(user/${user_data(${destination_number}@${domain_name} attr id)}@${domain_name}) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action answer() <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action sleep(1000) <o:p></o:p></p><p class=MsoNormal>Dialplan: sofia/internal/100@192.168.30.100:5060 Action voicemail(default ${domain_name} ${dialed_extension}) <o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/100@192.168.30.100:5060) State Change CS_ROUTING -> CS_EXECUTE<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/100@192.168.30.100:5060) State ROUTING going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/100@192.168.30.100:5060) Running State Change CS_EXECUTE<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/100@192.168.30.100:5060) State EXECUTE<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] mod_sofia.c:230 sofia/internal/100@192.168.30.100:5060 SOFIA EXECUTE<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:209 sofia/internal/100@192.168.30.100:5060 Standard EXECUTE<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(call_direction=local)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [call_direction]=[local]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-spymap/100/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-last_dial/100/110)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-last_dial/global/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(RFC2822_DATE=Thu, 26 Sep 2013 15:43:48 -0300)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [RFC2822_DATE]=[Thu, 26 Sep 2013 15:43:48 -0300]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(dialed_extension=110)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [dialed_extension]=[110]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 export(dialed_extension=110)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.517027 [DEBUG] switch_channel.c:1226 EXPORT (export_vars) [dialed_extension]=[110]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 limit(hash 192.168.30.100 110 5 )<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] switch_limit.c:126 incr called: 192.168.30.100_110 max:5, interval:0<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] mod_hash.c:202 Usage for 192.168.30.100_110 is now 1/5<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 bind_meta_app(1 b s execute_extension::dx XML features)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] switch_ivr_async.c:3630 Bound B-Leg: *1 execute_extension::dx XML features<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/archive/2013/Sep/26/ef19ab2c-f911-4480-8776-a43f91bd7a4f.wav)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] switch_ivr_async.c:3630 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/archive/2013/Sep/26/ef19ab2c-f911-4480-8776-a43f91bd7a4f.wav<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 bind_meta_app(3 b s execute_extension::cf XML features)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] switch_ivr_async.c:3630 Bound B-Leg: *3 execute_extension::cf XML features<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 bind_meta_app(4 b s execute_extension::att_xfer XML features)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [INFO] switch_ivr_async.c:3630 Bound B-Leg: *4 execute_extension::att_xfer XML features<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(ringback=%(2000, 4000, 440.0, 480.0))<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [ringback]=[%(2000, 4000, 440.0, 480.0)]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(transfer_ringback=local_stream://moh)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [transfer_ringback]=[local_stream://moh]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(call_timeout=30)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [call_timeout]=[30]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(hangup_after_bridge=true)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [hangup_after_bridge]=[true]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(continue_on_fail=true)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [continue_on_fail]=[true]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-call_return/110/100)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-last_dial_ext/110/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 set(called_party_call_group=sales, support, billing)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/100@192.168.30.100:5060 SET [called_party_call_group]=[sales, support, billing]<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 hash(insert/192.168.30.100-last_dial/sales, support, billing/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<o:p></o:p></p><p class=MsoNormal>EXECUTE sofia/internal/100@192.168.30.100:5060 bridge(user/110@192.168.30.100)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/100@192.168.30.100:5060 EXPORTING[export_vars] [domain_name]=[192.168.30.100] to event<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/100@192.168.30.100:5060 EXPORTING[export_vars] [dialed_extension]=[110] to event<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/100@192.168.30.100:5060 EXPORTING[export_vars] [domain_name]=[192.168.30.100] to event<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/100@192.168.30.100:5060 EXPORTING[export_vars] [dialed_extension]=[110] to event<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_event.c:1652 Parsing variable [sip_invite_domain]=[192.168.30.100]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_event.c:1652 Parsing variable [leg_timeout]=[30]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_event.c:1652 Parsing variable [presence_id]=[110@192.168.30.100]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [NOTICE] switch_channel.c:1034 New Channel sofia/internal/sip:110@192.168.30.50:5060 [4dc18443-2a92-44ba-b215-5c5dca4b67eb]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:4480 (sofia/internal/sip:110@192.168.30.50:5060) State Change CS_NEW -> CS_INIT<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2773 sofia/internal/sip:110@192.168.30.50:5060 Setting leg timeout to 30<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_INIT<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/sip:110@192.168.30.50:5060) State INIT<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:87 sofia/internal/sip:110@192.168.30.50:5060 SOFIA INIT<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] sofia_glue.c:1225 Local SDP:<o:p></o:p></p><p class=MsoNormal>v=0<o:p></o:p></p><p class=MsoNormal>o=FreeSWITCH 1380202374 1380202375 IN IP4 192.168.30.100<o:p></o:p></p><p class=MsoNormal>s=FreeSWITCH<o:p></o:p></p><p class=MsoNormal>c=IN IP4 192.168.30.100<o:p></o:p></p><p class=MsoNormal><span lang=FR-CA>t=0 0<o:p></o:p></span></p><p class=MsoNormal><span lang=FR-CA>m=audio 18654 RTP/AVP 0 9 8 3 101 13<o:p></o:p></span></p><p class=MsoNormal>a=rtpmap:101 telephone-event/8000<o:p></o:p></p><p class=MsoNormal>a=fmtp:101 0-16<o:p></o:p></p><p class=MsoNormal>a=ptime:20<o:p></o:p></p><p class=MsoNormal>a=sendrecv<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:114 (sofia/internal/sip:110@192.168.30.50:5060) State Change CS_INIT -> CS_ROUTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/sip:110@192.168.30.50:5060) State INIT going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_ROUTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/sip:110@192.168.30.50:5060) State ROUTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:137 sofia/internal/sip:110@192.168.30.50:5060 SOFIA ROUTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:110@192.168.30.50:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/sip:110@192.168.30.50:5060) State ROUTING going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_CONSUME_MEDIA<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/sip:110@192.168.30.50:5060) State CONSUME_MEDIA<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/sip:110@192.168.30.50:5060) State CONSUME_MEDIA going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.537011 [DEBUG] sofia.c:5834 Channel sofia/internal/sip:110@192.168.30.50:5060 entering state [calling][0]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] sofia.c:5834 Channel sofia/internal/sip:110@192.168.30.50:5060 entering state [proceeding][180]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [NOTICE] sofia.c:5924 Ring-Ready sofia/internal/sip:110@192.168.30.50:5060!<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_channel.c:3194 (sofia/internal/sip:110@192.168.30.50:5060) Callstate Change DOWN -> RINGING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [INFO] switch_ivr_originate.c:1190 Sending early media<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/100@192.168.30.100:5060] 192.168.30.100 port 23272 -> 192.168.30.50 port 16476 codec: 0 ms: 20<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_rtp.c:2881 Starting timer [soft] 160 bytes per 20ms<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4440 Set 2833 dtmf send payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4446 Set 2833 dtmf receive payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] mod_sofia.c:2143 Ring SDP:<o:p></o:p></p><p class=MsoNormal>v=0<o:p></o:p></p><p class=MsoNormal>o=FreeSWITCH 1380197756 1380197757 IN IP4 192.168.30.100<o:p></o:p></p><p class=MsoNormal>s=FreeSWITCH<o:p></o:p></p><p class=MsoNormal>c=IN IP4 192.168.30.100<o:p></o:p></p><p class=MsoNormal><span lang=FR-CA>t=0 0<o:p></o:p></span></p><p class=MsoNormal><span lang=FR-CA>m=audio 23272 RTP/AVP 0 101<o:p></o:p></span></p><p class=MsoNormal>a=rtpmap:0 PCMU/8000<o:p></o:p></p><p class=MsoNormal>a=rtpmap:101 telephone-event/8000<o:p></o:p></p><p class=MsoNormal>a=fmtp:101 0-16<o:p></o:p></p><p class=MsoNormal>a=ptime:20<o:p></o:p></p><p class=MsoNormal>a=sendrecv<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [NOTICE] mod_sofia.c:2146 Pre-Answer sofia/internal/100@192.168.30.100:5060!<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_channel.c:3332 (sofia/internal/100@192.168.30.100:5060) Callstate Change RINGING -> EARLY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:865 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_ivr_originate.c:1247 Raw Codec Activation Success L16@8000hz 1 channel 20ms<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.597004 [DEBUG] switch_core_codec.c:219 sofia/internal/100@192.168.30.100:5060 Push codec L16:70<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.616991 [DEBUG] switch_ivr_originate.c:1315 Play Ringback Tone [%(2000, 4000, 440.0, 480.0)]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.616991 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.637046 [DEBUG] sofia.c:5834 Channel sofia/internal/100@192.168.30.100:5060 entering state [early][183]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:48.677046 [DEBUG] switch_rtp.c:4934 Correct ip/port confirmed.<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5834 Channel sofia/internal/sip:110@192.168.30.50:5060 entering state [completing][200]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5844 Remote SDP:<o:p></o:p></p><p class=MsoNormal>v=0<o:p></o:p></p><p class=MsoNormal>o=- 8118578 8118578 IN IP4 192.168.30.50<o:p></o:p></p><p class=MsoNormal>s=-<o:p></o:p></p><p class=MsoNormal>c=IN IP4 192.168.30.50<o:p></o:p></p><p class=MsoNormal><span lang=FR-CA>t=0 0<o:p></o:p></span></p><p class=MsoNormal><span lang=FR-CA>m=audio 16478 RTP/AVP 0 101<o:p></o:p></span></p><p class=MsoNormal>a=rtpmap:0 PCMU/8000<o:p></o:p></p><p class=MsoNormal>a=rtpmap:101 telephone-event/8000<o:p></o:p></p><p class=MsoNormal>a=fmtp:101 0-15<o:p></o:p></p><p class=MsoNormal>a=ptime:20<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5834 Channel sofia/internal/sip:110@192.168.30.50:5060 entering state [ready][200]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:2880 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:1913 Set Codec sofia/internal/sip:110@192.168.30.50:5060 PCMU/8000 20 ms 160 samples 64000 bits<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:110@192.168.30.50:5060 Original read codec set to PCMU:0<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:3042 Set 2833 dtmf send payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/sip:110@192.168.30.50:5060] 192.168.30.100 port 18654 -> 192.168.30.50 port 16478 codec: 0 ms: 20<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.897038 [DEBUG] switch_rtp.c:2881 Starting timer [soft] 160 bytes per 20ms<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] sofia.c:5834 Channel sofia/internal/100@192.168.30.100:5060 entering state [terminated][487]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] sofia.c:6642 Hangup sofia/internal/100@192.168.30.100:5060 [CS_EXECUTE] [ORIGINATOR_CANCEL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_media.c:4440 Set 2833 dtmf send payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_media.c:4446 Set 2833 dtmf receive payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3139 Send signal sofia/internal/100@192.168.30.100:5060 [KILL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [INFO] mod_hash.c:304 Usage for 192.168.30.100_110 is now 0<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_codec.c:244 sofia/internal/100@192.168.30.100:5060 Restore previous codec PCMU:0.<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] sofia.c:6587 Channel [sofia/internal/sip:110@192.168.30.50:5060] has been answered<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_ivr_originate.c:3410 Hangup sofia/internal/sip:110@192.168.30.50:5060 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3139 Send signal sofia/internal/sip:110@192.168.30.50:5060 [KILL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_ivr_originate.c:3626 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_ivr_originate.c:2661 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_ivr_originate.c:3632 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3613 (sofia/internal/sip:110@192.168.30.50:5060) Callstate Change RINGING -> ACTIVE<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] sofia.c:6587 sofia/internal/sip:110@192.168.30.50:5060 skip receive message [ANSWER_EVENT] (channel is hungup already)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] sofia.c:1087 Channel is already hungup.<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/sip:110@192.168.30.50:5060) State HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:459 sofia/internal/sip:110@192.168.30.50:5060 Overriding SIP cause 487 with 487 from the other leg<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:465 Channel sofia/internal/sip:110@192.168.30.50:5060 hanging up, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [INFO] mod_dptools.c:3194 Originate Failed. Cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:2767 sofia/internal/100@192.168.30.100:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/100@192.168.30.100:5060) State EXECUTE going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/100@192.168.30.100:5060) Running State Change CS_HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/100@192.168.30.100:5060) State HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:465 Channel sofia/internal/100@192.168.30.100:5060 hanging up, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:517 Sending BYE to sofia/internal/sip:110@192.168.30.50:5060<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:110@192.168.30.50:5060 Standard HANGUP, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/sip:110@192.168.30.50:5060) State HANGUP going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:694 (sofia/internal/sip:110@192.168.30.50:5060) Callstate Change ACTIVE -> HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:110@192.168.30.50:5060) State Change CS_HANGUP -> CS_REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:48 sofia/internal/100@192.168.30.100:5060 Standard HANGUP, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/100@192.168.30.100:5060) State HANGUP going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:694 (sofia/internal/100@192.168.30.100:5060) Callstate Change EARLY -> HANGUP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/sip:110@192.168.30.50:5060) State REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:110@192.168.30.50:5060 Standard REPORTING, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/100@192.168.30.100:5060) State Change CS_HANGUP -> CS_REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/sip:110@192.168.30.50:5060) State REPORTING going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/100@192.168.30.100:5060) Running State Change CS_REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/100@192.168.30.100:5060) State REPORTING<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:443 (sofia/internal/sip:110@192.168.30.50:5060) State Change CS_REPORTING -> CS_DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/sip:110@192.168.30.50:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1553 Session 139 (sofia/internal/sip:110@192.168.30.50:5060) Locked, Waiting on external entities<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1571 Session 139 (sofia/internal/sip:110@192.168.30.50:5060) Ended<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1575 Close Channel sofia/internal/sip:110@192.168.30.50:5060 [CS_DESTROY]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/sip:110@192.168.30.50:5060) Callstate Change HANGUP -> DOWN<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:571 (sofia/internal/sip:110@192.168.30.50:5060) Running State Change CS_DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/sip:110@192.168.30.50:5060) State DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:375 sofia/internal/sip:110@192.168.30.50:5060 SOFIA DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:110@192.168.30.50:5060 Standard DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/sip:110@192.168.30.50:5060) State DESTROY going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:92 sofia/internal/100@192.168.30.100:5060 Standard REPORTING, cause: ORIGINATOR_CANCEL<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/100@192.168.30.100:5060) State REPORTING going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:443 (sofia/internal/100@192.168.30.100:5060) State Change CS_REPORTING -> CS_DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1553 Session 138 (sofia/internal/100@192.168.30.100:5060) Locked, Waiting on external entities<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1571 Session 138 (sofia/internal/100@192.168.30.100:5060) Ended<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1575 Close Channel sofia/internal/100@192.168.30.100:5060 [CS_DESTROY]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/100@192.168.30.100:5060) Callstate Change HANGUP -> DOWN<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:571 (sofia/internal/100@192.168.30.100:5060) Running State Change CS_DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.30.100:5060) State DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.937028 [DEBUG] mod_sofia.c:375 sofia/internal/100@192.168.30.100:5060 SOFIA DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:99 sofia/internal/100@192.168.30.100:5060 Standard DESTROY<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/100@192.168.30.100:5060) State DESTROY going to sleep<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.637066 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.637066 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.657060 [DEBUG] sofia.c:5834 Channel sofia/internal/100@192.168.30.100:5060 entering state [received][100]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.657060 [DEBUG] sofia.c:5844 Remote SDP:<o:p></o:p></p><p class=MsoNormal>v=0<o:p></o:p></p><p class=MsoNormal>o=- 8119682 8119682 IN IP4 192.168.30.50<o:p></o:p></p><p class=MsoNormal>s=-<o:p></o:p></p><p class=MsoNormal>c=IN IP4 192.168.30.50<o:p></o:p></p><p class=MsoNormal><span lang=FR-CA>t=0 0<o:p></o:p></span></p><p class=MsoNormal><span lang=FR-CA>m=audio 16466 RTP/AVP 0 8 101<o:p></o:p></span></p><p class=MsoNormal>a=rtpmap:0 PCMU/8000<o:p></o:p></p><p class=MsoNormal>a=rtpmap:8 PCMA/8000<o:p></o:p></p><p class=MsoNormal>a=rtpmap:101 telephone-event/8000<o:p></o:p></p><p class=MsoNormal>a=fmtp:101 0-15<o:p></o:p></p><p class=MsoNormal>a=ptime:20<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_ivr_play_say.c:1723 done playing file local_stream://moh<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_channel.c:1909 (sofia/internal/100@192.168.30.100:5060) Callstate Change HELD -> UNHOLD<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_session.c:865 Send signal sofia/external/15068580441 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_ivr_bridge.c:388 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:2880 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:1841 Already using PCMU<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:3051 Set 2833 dtmf send/recv payload to 101<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4087 Audio params changed for sofia/internal/100@192.168.30.100:5060 from 0.0.0.0:16466 to 192.168.30.50:16466<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/100@192.168.30.100:5060] 192.168.30.100 port 29654 -> 192.168.30.50 port 16466 codec: 0 ms: 20<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4139 AUDIO RTP CHANGING DEST TO: [192.168.30.50:16466]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] sofia.c:6375 Processing updated SDP<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.917060 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.937039 [DEBUG] sofia.c:5834 Channel sofia/internal/100@192.168.30.100:5060 entering state [completed][200]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/100@192.168.30.100:5060 [BREAK]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:43:59.937039 [DEBUG] sofia.c:5834 Channel sofia/internal/100@192.168.30.100:5060 entering state [ready][200]<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:44:00.097064 [DEBUG] switch_rtp.c:4934 Correct ip/port confirmed.<o:p></o:p></p><p class=MsoNormal>2013-09-26 15:44:52.197015 [DEBUG] sofia_reg.c:2234 Changing expire time to 600 by request of proxy sip:sip-slb.voicemeup.com<o:p></o:p></p></div></body></html>