<div dir="ltr">Hi Charles,<div><br></div><div>Sorry for the delayed response, looks like the ML was fairly quiet over the weekend.</div><div><br></div><div>Your email mentioned that you didn't know where/why this was being sent to voicemail - have you taken a look at your dialplan first? According to your logs, it attempts to bridge first, then goes to email upon failure. Can you tell us a few things;</div>
<div><br></div><div>* Does the callee (the phone being called) ring?</div><div>* Does the caller (the phone making the call) hear a ringback tone?</div><div>* How long does the phone ring before going to voicemail?</div><div>
* Have you been able to find a fix for this so far?</div><div><br></div><div>Generally speaking, if the bridge fails then the callee was unable to take the call thus it proceeds to the next step in the dialplan. Sometimes NAT problems can cause this to happen too.<br>
</div><div><br></div><div>Once you've ascertained the above, you can attempt to fix the problem. For example, if the phone is not ringing then this would suggest a registration problem, if the phone is registered fine then this could be a NAT issue. If the phone is ringing, what happens when you pick up? Etc etc.</div>
<div><br></div><div>Also - in future please paste any logs directly into pastebin and provide a URL, large chunks of debug become malformed and make reading a struggle.</div><div><br></div><div>Cal</div><div><br></div><div>
<br></div><div><br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Sep 26, 2013 at 8:11 PM, Charles Bujold <span dir="ltr"><<a href="mailto:cjbujold@accra.ca" target="_blank">cjbujold@accra.ca</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div lang="EN-CA" link="#0563C1" vlink="#954F72"><div><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. <u></u><u></u></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.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Regex (PASS) [local_extension] destination_number(110) =~ /(^\d{2,7}$)/ break=on-false<u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(dialed_extension=110) <u></u><u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action export(dialed_extension=110) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action limit(hash ${domain_name} 110 ${limit_max} ${limit_destination}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action bind_meta_app(1 b s execute_extension::dx XML features) <u></u><u></u></p><p class="MsoNormal">
Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.wav) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action bind_meta_app(3 b s execute_extension::cf XML features) <u></u><u></u></p><p class="MsoNormal">
Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action bind_meta_app(4 b s execute_extension::att_xfer XML features) <u></u><u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(ringback=${us-ring}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(transfer_ringback=local_stream://moh) <u></u><u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(call_timeout=30) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(hangup_after_bridge=true) <u></u><u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(continue_on_fail=true) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action bridge(user/${user_data(${destination_number}@${domain_name} attr id)}@${domain_name}) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action answer() <u></u><u></u></p><p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action sleep(1000) <u></u><u></u></p>
<p class="MsoNormal">Dialplan: sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Action voicemail(default ${domain_name} ${dialed_extension}) <u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State Change CS_ROUTING -> CS_EXECUTE<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State ROUTING going to sleep<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Running State Change CS_EXECUTE<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State EXECUTE<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.517027 [DEBUG] mod_sofia.c:230 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SOFIA EXECUTE<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] switch_core_state_machine.c:209 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Standard EXECUTE<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(call_direction=local)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [call_direction]=[local]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-spymap/100/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-last_dial/100/110)<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-last_dial/global/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(RFC2822_DATE=Thu, 26 Sep 2013 15:43:48 -0300)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [RFC2822_DATE]=[Thu, 26 Sep 2013 15:43:48 -0300]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(dialed_extension=110)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [dialed_extension]=[110]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> export(dialed_extension=110)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.517027 [DEBUG] switch_channel.c:1226 EXPORT (export_vars) [dialed_extension]=[110]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> limit(hash 192.168.30.100 110 5 )<u></u><u></u></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<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> bind_meta_app(1 b s execute_extension::dx XML features)<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/archive/2013/Sep/26/ef19ab2c-f911-4480-8776-a43f91bd7a4f.wav)<u></u><u></u></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<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> bind_meta_app(3 b s execute_extension::cf XML features)<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> bind_meta_app(4 b s execute_extension::att_xfer XML features)<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(ringback=%(2000, 4000, 440.0, 480.0))<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [ringback]=[%(2000, 4000, 440.0, 480.0)]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(transfer_ringback=local_stream://moh)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [transfer_ringback]=[local_stream://moh]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(call_timeout=30)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [call_timeout]=[30]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(hangup_after_bridge=true)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [hangup_after_bridge]=[true]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(continue_on_fail=true)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [continue_on_fail]=[true]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-call_return/110/100)<u></u><u></u></p><p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-last_dial_ext/110/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> set(called_party_call_group=sales, support, billing)<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_dptools.c:1395 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SET [called_party_call_group]=[sales, support, billing]<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hash(insert/192.168.30.100-last_dial/sales, support, billing/ef19ab2c-f911-4480-8776-a43f91bd7a4f)<u></u><u></u></p>
<p class="MsoNormal">EXECUTE sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> bridge(user/<a href="mailto:110@192.168.30.100" target="_blank">110@192.168.30.100</a>)<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> EXPORTING[export_vars] [domain_name]=[192.168.30.100] to event<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> EXPORTING[export_vars] [dialed_extension]=[110] to event<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> EXPORTING[export_vars] [domain_name]=[192.168.30.100] to event<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_channel.c:1180 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> EXPORTING[export_vars] [dialed_extension]=[110] to event<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables<u></u><u></u></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]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_event.c:1652 Parsing variable [leg_timeout]=[30]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_event.c:1652 Parsing variable [presence_id]=[<a href="mailto:110@192.168.30.100" target="_blank">110@192.168.30.100</a>]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [NOTICE] switch_channel.c:1034 New Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [4dc18443-2a92-44ba-b215-5c5dca4b67eb]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:4480 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State Change CS_NEW -> CS_INIT<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:2773 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Setting leg timeout to 30<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_INIT<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State INIT<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:87 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> SOFIA INIT<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.537011 [DEBUG] sofia_glue.c:1225 Local SDP:<u></u><u></u></p><p class="MsoNormal">v=0<u></u><u></u></p><p class="MsoNormal">o=FreeSWITCH 1380202374 1380202375 IN IP4 192.168.30.100<u></u><u></u></p><p class="MsoNormal">
s=FreeSWITCH<u></u><u></u></p><p class="MsoNormal">c=IN IP4 192.168.30.100<u></u><u></u></p><p class="MsoNormal"><span lang="FR-CA">t=0 0<u></u><u></u></span></p><p class="MsoNormal"><span lang="FR-CA">m=audio 18654 RTP/AVP 0 9 8 3 101 13<u></u><u></u></span></p>
<p class="MsoNormal">a=rtpmap:101 telephone-event/8000<u></u><u></u></p><p class="MsoNormal">a=fmtp:101 0-16<u></u><u></u></p><p class="MsoNormal">a=ptime:20<u></u><u></u></p><p class="MsoNormal">a=sendrecv<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:114 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State Change CS_INIT -> CS_ROUTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State INIT going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_ROUTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State ROUTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] mod_sofia.c:137 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> SOFIA ROUTING<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.537011 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State Change CS_ROUTING -> CS_CONSUME_MEDIA<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State ROUTING going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_CONSUME_MEDIA<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State CONSUME_MEDIA<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State CONSUME_MEDIA going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.537011 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> entering state [calling][0]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> entering state [proceeding][180]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [NOTICE] sofia.c:5924 Ring-Ready sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>!<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.597004 [DEBUG] switch_channel.c:3194 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Callstate Change DOWN -> RINGING<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:48.597004 [INFO] switch_ivr_originate.c:1190 Sending early media<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>] 192.168.30.100 port 23272 -> 192.168.30.50 port 16476 codec: 0 ms: 20<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_rtp.c:2881 Starting timer [soft] 160 bytes per 20ms<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4440 Set 2833 dtmf send payload to 101<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_media.c:4446 Set 2833 dtmf receive payload to 101<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] mod_sofia.c:2143 Ring SDP:<u></u><u></u></p>
<p class="MsoNormal">v=0<u></u><u></u></p><p class="MsoNormal">o=FreeSWITCH 1380197756 1380197757 IN IP4 192.168.30.100<u></u><u></u></p><p class="MsoNormal">s=FreeSWITCH<u></u><u></u></p><p class="MsoNormal">c=IN IP4 192.168.30.100<u></u><u></u></p>
<p class="MsoNormal"><span lang="FR-CA">t=0 0<u></u><u></u></span></p><p class="MsoNormal"><span lang="FR-CA">m=audio 23272 RTP/AVP 0 101<u></u><u></u></span></p><p class="MsoNormal">a=rtpmap:0 PCMU/8000<u></u><u></u></p>
<p class="MsoNormal">a=rtpmap:101 telephone-event/8000<u></u><u></u></p><p class="MsoNormal">a=fmtp:101 0-16<u></u><u></u></p><p class="MsoNormal">a=ptime:20<u></u><u></u></p><p class="MsoNormal">a=sendrecv<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal">2013-09-26 15:43:48.597004 [NOTICE] mod_sofia.c:2146 Pre-Answer sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>!<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_channel.c:3332 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Callstate Change RINGING -> EARLY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_session.c:865 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.597004 [DEBUG] switch_core_codec.c:219 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Push codec L16:70<u></u><u></u></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)]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:48.616991 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.637046 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> entering state [early][183]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:48.677046 [DEBUG] switch_rtp.c:4934 Correct ip/port confirmed.<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> entering state [completing][200]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5844 Remote SDP:<u></u><u></u></p><p class="MsoNormal">v=0<u></u><u></u></p><p class="MsoNormal">o=- 8118578 8118578 IN IP4 192.168.30.50<u></u><u></u></p><p class="MsoNormal">
s=-<u></u><u></u></p><p class="MsoNormal">c=IN IP4 192.168.30.50<u></u><u></u></p><p class="MsoNormal"><span lang="FR-CA">t=0 0<u></u><u></u></span></p><p class="MsoNormal"><span lang="FR-CA">m=audio 16478 RTP/AVP 0 101<u></u><u></u></span></p>
<p class="MsoNormal">a=rtpmap:0 PCMU/8000<u></u><u></u></p><p class="MsoNormal">a=rtpmap:101 telephone-event/8000<u></u><u></u></p><p class="MsoNormal">a=fmtp:101 0-15<u></u><u></u></p><p class="MsoNormal">a=ptime:20<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> entering state [ready][200]<u></u><u></u></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]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:1913 Set Codec sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> PCMU/8000 20 ms 160 samples 64000 bits<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_codec.c:111 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Original read codec set to PCMU:0<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:3042 Set 2833 dtmf send payload to 101<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>] 192.168.30.100 port 18654 -> 192.168.30.50 port 16478 codec: 0 ms: 20<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.897038 [DEBUG] switch_rtp.c:2881 Starting timer [soft] 160 bytes per 20ms<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> entering state [terminated][487]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] sofia.c:6642 Hangup sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [CS_EXECUTE] [ORIGINATOR_CANCEL]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_media.c:4440 Set 2833 dtmf send payload to 101<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_media.c:4446 Set 2833 dtmf receive payload to 101<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3139 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [KILL]<u></u><u></u></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<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_codec.c:244 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Restore previous codec PCMU:0.<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] sofia.c:6587 Channel [sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>] has been answered<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] switch_ivr_originate.c:3410 Hangup sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3139 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [KILL]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></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]<u></u><u></u></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]<u></u><u></u></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]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_channel.c:3613 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Callstate Change RINGING -> ACTIVE<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] sofia.c:6587 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> skip receive message [ANSWER_EVENT] (channel is hungup already)<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] sofia.c:1087 Channel is already hungup.<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_HANGUP<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State HANGUP<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:459 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Overriding SIP cause 487 with 487 from the other leg<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:465 Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> hanging up, cause: ORIGINATOR_CANCEL<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [INFO] mod_dptools.c:3194 Originate Failed. Cause: ORIGINATOR_CANCEL<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:2767 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State EXECUTE going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Running State Change CS_HANGUP<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State HANGUP<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:465 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> hanging up, cause: ORIGINATOR_CANCEL<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:517 Sending BYE to sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a><u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:48 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Standard HANGUP, cause: ORIGINATOR_CANCEL<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State HANGUP going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:694 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Callstate Change ACTIVE -> HANGUP<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State Change CS_HANGUP -> CS_REPORTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_REPORTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:48 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Standard HANGUP, cause: ORIGINATOR_CANCEL<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:681 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State HANGUP going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:694 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Callstate Change EARLY -> HANGUP<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State REPORTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:92 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Standard REPORTING, cause: ORIGINATOR_CANCEL<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State Change CS_HANGUP -> CS_REPORTING<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State REPORTING going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:418 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Running State Change CS_REPORTING<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State REPORTING<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:443 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State Change CS_REPORTING -> CS_DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1553 Session 139 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Locked, Waiting on external entities<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1571 Session 139 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Ended<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1575 Close Channel sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> [CS_DESTROY]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Callstate Change HANGUP -> DOWN<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:571 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) Running State Change CS_DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] mod_sofia.c:375 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> SOFIA DESTROY<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:99 sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a> Standard DESTROY<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/<a href="http://sip:110@192.168.30.50:5060" target="_blank">sip:110@192.168.30.50:5060</a>) State DESTROY going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:92 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Standard REPORTING, cause: ORIGINATOR_CANCEL<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:766 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State REPORTING going to sleep<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:443 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State Change CS_REPORTING -> CS_DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1345 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.917046 [DEBUG] switch_core_session.c:1553 Session 138 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Locked, Waiting on external entities<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1571 Session 138 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Ended<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [NOTICE] switch_core_session.c:1575 Close Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [CS_DESTROY]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.917046 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Callstate Change HANGUP -> DOWN<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:571 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Running State Change CS_DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State DESTROY<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:52.937028 [DEBUG] mod_sofia.c:375 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> SOFIA DESTROY<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:99 sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> Standard DESTROY<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:52.937028 [DEBUG] switch_core_state_machine.c:581 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) State DESTROY going to sleep<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:59.637066 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:59.637066 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.657060 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> entering state [received][100]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.657060 [DEBUG] sofia.c:5844 Remote SDP:<u></u><u></u></p><p class="MsoNormal">v=0<u></u><u></u></p><p class="MsoNormal">o=- 8119682 8119682 IN IP4 192.168.30.50<u></u><u></u></p><p class="MsoNormal">
s=-<u></u><u></u></p><p class="MsoNormal">c=IN IP4 192.168.30.50<u></u><u></u></p><p class="MsoNormal"><span lang="FR-CA">t=0 0<u></u><u></u></span></p><p class="MsoNormal"><span lang="FR-CA">m=audio 16466 RTP/AVP 0 8 101<u></u><u></u></span></p>
<p class="MsoNormal">a=rtpmap:0 PCMU/8000<u></u><u></u></p><p class="MsoNormal">a=rtpmap:8 PCMA/8000<u></u><u></u></p><p class="MsoNormal">a=rtpmap:101 telephone-event/8000<u></u><u></u></p><p class="MsoNormal">a=fmtp:101 0-15<u></u><u></u></p>
<p class="MsoNormal">a=ptime:20<u></u><u></u></p><p class="MsoNormal"><u></u> <u></u></p><p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_ivr_play_say.c:1723 done playing file local_stream://moh<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_channel.c:1909 (sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>) Callstate Change HELD -> UNHOLD<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_session.c:865 Send signal sofia/external/<a href="tel:15068580441" value="+15068580441" target="_blank">15068580441</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:59.917060 [DEBUG] switch_ivr_bridge.c:388 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></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]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:1841 Already using PCMU<u></u><u></u></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<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4087 Audio params changed for sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> from <a href="http://0.0.0.0:16466" target="_blank">0.0.0.0:16466</a> to <a href="http://192.168.30.50:16466" target="_blank">192.168.30.50:16466</a><u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4098 AUDIO RTP [sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a>] 192.168.30.100 port 29654 -> 192.168.30.50 port 16466 codec: 0 ms: 20<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_media.c:4139 AUDIO RTP CHANGING DEST TO: [<a href="http://192.168.30.50:16466" target="_blank">192.168.30.50:16466</a>]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:59.917060 [DEBUG] sofia.c:6375 Processing updated SDP<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:59.917060 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">2013-09-26 15:43:59.937039 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> entering state [completed][200]<u></u><u></u></p>
<p class="MsoNormal">2013-09-26 15:43:59.937039 [DEBUG] switch_core_session.c:1010 Send signal sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> [BREAK]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:43:59.937039 [DEBUG] sofia.c:5834 Channel sofia/internal/<a href="http://100@192.168.30.100:5060" target="_blank">100@192.168.30.100:5060</a> entering state [ready][200]<u></u><u></u></p><p class="MsoNormal">
2013-09-26 15:44:00.097064 [DEBUG] switch_rtp.c:4934 Correct ip/port confirmed.<u></u><u></u></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:<a href="http://sip-slb.voicemeup.com" target="_blank">sip-slb.voicemeup.com</a><u></u><u></u></p>
</div></div><br>_________________________________________________________________________<br>
Professional FreeSWITCH Consulting Services:<br>
<a href="mailto:consulting@freeswitch.org">consulting@freeswitch.org</a><br>
<a href="http://www.freeswitchsolutions.com" target="_blank">http://www.freeswitchsolutions.com</a><br>
<br>
FreeSWITCH-powered IP PBX: The CudaTel Communication Server<br>
<a href="http://www.cudatel.com" target="_blank">http://www.cudatel.com</a><br>
<br>
Official FreeSWITCH Sites<br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<a href="http://wiki.freeswitch.org" target="_blank">http://wiki.freeswitch.org</a><br>
<a href="http://www.cluecon.com" target="_blank">http://www.cluecon.com</a><br>
<br>
FreeSWITCH-users mailing list<br>
<a href="mailto:FreeSWITCH-users@lists.freeswitch.org">FreeSWITCH-users@lists.freeswitch.org</a><br>
<a href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/listinfo/freeswitch-users</a><br>
UNSUBSCRIBE:<a href="http://lists.freeswitch.org/mailman/options/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/options/freeswitch-users</a><br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<br></blockquote></div><br></div>