Can you drop this into pastebin? <a href="http://pastebin.freeswitch.org">pastebin.freeswitch.org</a>. Also include the dialplan that is running all this. Use the "freeswitch log" syntax highlighting because it makes it much easier to read.<div>
<br></div><div>-MC<br><br><div class="gmail_quote">On Wed, Mar 23, 2011 at 4:49 PM, Brian May <span dir="ltr"><<a href="mailto:brian@microcomaustralia.com.au">brian@microcomaustralia.com.au</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex;">
When freeswitch answers the call, everything seems fine at first, but<br>
then it redirects the call to the magic number of 6201 which fails<br>
because I haven't defined this number anywhere. For an incoming SIP<br>
call the call is hang up after the first ring. For an incoming call<br>
from FreeDTM, callerid doesn't work, and the phone keeps ringing<br>
randomly until well after the caller has hang up. As it a result it is<br>
not possible to answer the incoming call.<br>
<br>
At first I thought maybe a problem with my analog telephone line, I<br>
think I have ruled this out now that I see similar logs for SIP calls.<br>
<br>
What is weird is that I haven't made any changes to the setup, and<br>
everything was working fine until yesterday.<br>
<br>
Here is an excerpt from my logs for an incoming SIP call. Where is<br>
this magic number of 6201 coming from? I did a grep of all my config<br>
files and came up with nothing.<br>
<br>
Last night I rebooted the box, it worked for one call, then failed for<br>
subsequent calls.<br>
<br>
<br>
Any ideas??<br>
<br>
<br>
Thanks<br>
<br>
<br>
<br>
2011-03-24 10:31:22.061336 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET<br>
[dialed_extension]=[2000]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a><br>
export(dialed_extension=2000)<br>
2011-03-24 10:31:22.080434 [DEBUG] mod_dptools.c:938 EXPORT<br>
[dialed_extension]=[2000]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> bind_meta_app(1 b<br>
s execute_extension::dx XML features)<br>
2011-03-24 10:31:22.095423 [INFO] switch_ivr_async.c:2464 Bound B-Leg:<br>
*1 execute_extension::dx XML features<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> bind_meta_app(2 b<br>
s record_session::/opt/freeswitch/recordings/1004.2011-03-24-10-31-22.wav)<br>
2011-03-24 10:31:22.116351 [INFO] switch_ivr_async.c:2464 Bound B-Leg:<br>
*2 record_session::/opt/freeswitch/recordings/1004.2011-03-24-10-31-22.wav<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> bind_meta_app(3 b<br>
s execute_extension::cf XML features)<br>
2011-03-24 10:31:22.130335 [INFO] switch_ivr_async.c:2464 Bound B-Leg:<br>
*3 execute_extension::cf XML features<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> set(ringback=)<br>
2011-03-24 10:31:22.141503 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET [ringback]=[UNDEF]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a><br>
set(transfer_ringback=local_stream://moh)<br>
2011-03-24 10:31:22.164352 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET<br>
[transfer_ringback]=[local_stream://moh]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> set(call_timeout=30)<br>
2011-03-24 10:31:22.179416 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET [call_timeout]=[30]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a><br>
set(hangup_after_bridge=true)<br>
2011-03-24 10:31:22.192366 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET<br>
[hangup_after_bridge]=[true]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> set(continue_on_fail=true)<br>
2011-03-24 10:31:22.206368 [DEBUG] mod_dptools.c:854<br>
sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a> SET<br>
[continue_on_fail]=[true]<br>
EXECUTE sofia/internal/<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a><br>
bridge([presence_id=<a href="mailto:1000@microcomaustralia.com.au">1000@microcomaustralia.com.au</a>]error/user_not_registered,FreeTDM/1/1,[presence_id=<a href="mailto:1001@microcomaustralia.com.au">1001@microcomaustralia.com.au</a>]error/user_not_registered,FreeTDM/2/1,[presence_id=<a href="mailto:1002@microcomaustralia.com.au">1002@microcomaustralia.com.au</a>]sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>,[presence_id=<a href="mailto:1003@microcomaustralia.com.au">1003@microcomaustralia.com.au</a>]sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>,[presence_id=<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a>]sofia/internal/<a href="mailto:sip%3A1004@192.168.2.16">sip:1004@192.168.2.16</a>)<br>
<br>
Everything fine up to (and beyond) this point.<br>
<br>
<br>
2011-03-24 10:31:22.374349 [DEBUG] switch_ivr_originate.c:2599 local<br>
variable string 0 = [presence_id=<a href="mailto:1000@microcomaustralia.com.au">1000@microcomaustralia.com.au</a>]<br>
2011-03-24 10:31:22.374349 [ERR] switch_ivr_originate.c:2632 Cannot<br>
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]<br>
2011-03-24 10:31:22.380323 [INFO] ftmod_zt.c:636 Setting echo cancel<br>
to 64 taps for 1:1<br>
2011-03-24 10:31:22.381586 [DEBUG] mod_freetdm.c:377 Set codec PCMU 20ms<br>
2011-03-24 10:31:22.393312 [DEBUG] mod_freetdm.c:1334 Connect outbound<br>
channel FreeTDM/1:1/<br>
2011-03-24 10:31:22.393312 [NOTICE] switch_channel.c:779 New Channel<br>
FreeTDM/1:1/ [d1b1124a-e8cf-485a-8c1e-dafbcaf0d09b]<br>
2011-03-24 10:31:22.399504 [DEBUG] mod_freetdm.c:1348 (FreeTDM/1:1/)<br>
State Change CS_NEW -> CS_INIT<br>
2011-03-24 10:31:22.399504 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/1:1/ [BREAK]<br>
2011-03-24 10:31:22.399504 [DEBUG] ftmod_analog.c:361 [s1c1][1:1]<br>
ANALOG CHANNEL thread starting.<br>
2011-03-24 10:31:22.404683 [DEBUG] ftmod_analog.c:88 [s1c1][1:1]<br>
Changed state from DOWN to GENRING<br>
2011-03-24 10:31:23.514411 [INFO] ftmod_zt.c:636 Setting echo cancel<br>
to 64 taps for 1:1<br>
2011-03-24 10:31:23.514411 [DEBUG] ftdm_io.c:2539 [s1c1][1:1] Enabled<br>
software DTMF detector<br>
2011-03-24 10:31:23.514411 [DEBUG] ftmod_analog.c:381 [s1c1][1:1]<br>
Initialized DTMF detection<br>
2011-03-24 10:31:23.514411 [DEBUG] ftmod_analog.c:534 [s1c1][1:1]<br>
Executing state handler on 1:1 for GENRING<br>
2011-03-24 10:31:23.514411 [DEBUG] mod_freetdm.c:1715 got FXS sig [PROGRESS]<br>
2011-03-24 10:31:23.514411 [NOTICE] mod_freetdm.c:1732 Ring-Ready FreeTDM/1:1/!<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/1:1/) Running State Change CS_INIT<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:338<br>
(FreeTDM/1:1/) State INIT<br>
2011-03-24 10:31:23.525898 [DEBUG] mod_freetdm.c:405 (FreeTDM/1:1/)<br>
State Change CS_INIT -> CS_ROUTING<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/1:1/ [BREAK]<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:338<br>
(FreeTDM/1:1/) State INIT going to sleep<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/1:1/) Running State Change CS_ROUTING<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_channel.c:1512<br>
(FreeTDM/1:1/) Callstate Change DOWN -> RINGING<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:341<br>
(FreeTDM/1:1/) State ROUTING<br>
2011-03-24 10:31:23.525898 [DEBUG] mod_freetdm.c:428 FreeTDM/1:1/<br>
CHANNEL ROUTING<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_ivr_originate.c:66<br>
(FreeTDM/1:1/) State Change CS_ROUTING -> CS_CONSUME_MEDIA<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/1:1/ [BREAK]<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:341<br>
(FreeTDM/1:1/) State ROUTING going to sleep<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/1:1/) Running State Change CS_CONSUME_MEDIA<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:360<br>
(FreeTDM/1:1/) State CONSUME_MEDIA<br>
2011-03-24 10:31:23.525898 [DEBUG] switch_core_state_machine.c:360<br>
(FreeTDM/1:1/) State CONSUME_MEDIA going to sleep<br>
2011-03-24 10:31:23.536490 [DEBUG] switch_ivr_originate.c:2599 local<br>
variable string 0 = [presence_id=<a href="mailto:1001@microcomaustralia.com.au">1001@microcomaustralia.com.au</a>]<br>
2011-03-24 10:31:23.538398 [ERR] switch_ivr_originate.c:2632 Cannot<br>
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]<br>
2011-03-24 10:31:23.538398 [INFO] ftmod_zt.c:636 Setting echo cancel<br>
to 64 taps for 2:1<br>
2011-03-24 10:31:23.544342 [DEBUG] mod_freetdm.c:377 Set codec PCMU 20ms<br>
2011-03-24 10:31:23.551431 [DEBUG] mod_freetdm.c:1334 Connect outbound<br>
channel FreeTDM/2:1/<br>
2011-03-24 10:31:23.555384 [NOTICE] switch_channel.c:779 New Channel<br>
FreeTDM/2:1/ [86275359-c4be-4663-9561-c5973344c1a7]<br>
2011-03-24 10:31:23.559646 [DEBUG] mod_freetdm.c:1348 (FreeTDM/2:1/)<br>
State Change CS_NEW -> CS_INIT<br>
2011-03-24 10:31:23.561459 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/2:1/ [BREAK]<br>
2011-03-24 10:31:23.561459 [DEBUG] ftmod_analog.c:361 [s2c1][1:2]<br>
ANALOG CHANNEL thread starting.<br>
2011-03-24 10:31:23.565467 [DEBUG] ftmod_analog.c:88 [s2c1][1:2]<br>
Changed state from DOWN to GENRING<br>
2011-03-24 10:31:24.665349 [INFO] ftmod_zt.c:636 Setting echo cancel<br>
to 64 taps for 2:1<br>
2011-03-24 10:31:24.665349 [DEBUG] ftdm_io.c:2539 [s2c1][1:2] Enabled<br>
software DTMF detector<br>
2011-03-24 10:31:24.665349 [DEBUG] ftmod_analog.c:381 [s2c1][1:2]<br>
Initialized DTMF detection<br>
2011-03-24 10:31:24.665349 [DEBUG] ftmod_analog.c:534 [s2c1][1:2]<br>
Executing state handler on 2:1 for GENRING<br>
2011-03-24 10:31:24.665349 [DEBUG] mod_freetdm.c:1715 got FXS sig [PROGRESS]<br>
2011-03-24 10:31:24.665349 [NOTICE] mod_freetdm.c:1732 Ring-Ready FreeTDM/2:1/!<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/2:1/) Running State Change CS_INIT<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:338<br>
(FreeTDM/2:1/) State INIT<br>
2011-03-24 10:31:24.677691 [DEBUG] mod_freetdm.c:405 (FreeTDM/2:1/)<br>
State Change CS_INIT -> CS_ROUTING<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/2:1/ [BREAK]<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:338<br>
(FreeTDM/2:1/) State INIT going to sleep<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/2:1/) Running State Change CS_ROUTING<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_channel.c:1512<br>
(FreeTDM/2:1/) Callstate Change DOWN -> RINGING<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:341<br>
(FreeTDM/2:1/) State ROUTING<br>
2011-03-24 10:31:24.677691 [DEBUG] mod_freetdm.c:428 FreeTDM/2:1/<br>
CHANNEL ROUTING<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_ivr_originate.c:66<br>
(FreeTDM/2:1/) State Change CS_ROUTING -> CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_session.c:1047 Send<br>
signal FreeTDM/2:1/ [BREAK]<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:341<br>
(FreeTDM/2:1/) State ROUTING going to sleep<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:314<br>
(FreeTDM/2:1/) Running State Change CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:360<br>
(FreeTDM/2:1/) State CONSUME_MEDIA<br>
2011-03-24 10:31:24.677691 [DEBUG] switch_core_state_machine.c:360<br>
(FreeTDM/2:1/) State CONSUME_MEDIA going to sleep<br>
2011-03-24 10:31:24.692818 [DEBUG] switch_ivr_originate.c:2599 local<br>
variable string 0 = [presence_id=<a href="mailto:1002@microcomaustralia.com.au">1002@microcomaustralia.com.au</a>]<br>
2011-03-24 10:31:24.697423 [NOTICE] switch_channel.c:779 New Channel<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a><br>
[0da6383c-4633-4a03-99ed-839918a74161]<br>
2011-03-24 10:31:24.737484 [DEBUG] mod_sofia.c:3920<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State Change CS_NEW -><br>
CS_INIT<br>
2011-03-24 10:31:24.737484 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> [BREAK]<br>
2011-03-24 10:31:24.752679 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) Running State Change<br>
CS_INIT<br>
2011-03-24 10:31:24.756503 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State INIT<br>
2011-03-24 10:31:24.758368 [DEBUG] mod_sofia.c:83<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> SOFIA INIT<br>
2011-03-24 10:31:24.777518 [DEBUG] mod_sofia.c:123<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State Change CS_INIT -><br>
CS_ROUTING<br>
2011-03-24 10:31:24.777518 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> [BREAK]<br>
2011-03-24 10:31:24.777518 [DEBUG] sofia.c:4402 Channel<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> entering state [calling][0]<br>
2011-03-24 10:31:24.781657 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State INIT going to sleep<br>
2011-03-24 10:31:24.781657 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) Running State Change<br>
CS_ROUTING<br>
2011-03-24 10:31:24.785366 [DEBUG] switch_channel.c:1512<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) Callstate Change DOWN -><br>
RINGING<br>
2011-03-24 10:31:24.799334 [INFO] sofia.c:709<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> Update Callee ID to "1002"<br>
<1002><br>
2011-03-24 10:31:24.808910 [DEBUG] switch_core_state_machine.c:341<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State ROUTING<br>
2011-03-24 10:31:24.808910 [DEBUG] sofia.c:4402 Channel<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> entering state<br>
[proceeding][180]<br>
2011-03-24 10:31:24.812354 [NOTICE] sofia.c:4474 Ring-Ready<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>!<br>
2011-03-24 10:31:24.815429 [DEBUG] mod_sofia.c:146<br>
sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> SOFIA ROUTING<br>
2011-03-24 10:31:24.815429 [DEBUG] switch_ivr_originate.c:66<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State Change CS_ROUTING -><br>
CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.815429 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a> [BREAK]<br>
2011-03-24 10:31:24.815429 [DEBUG] switch_core_state_machine.c:341<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State ROUTING going to<br>
sleep<br>
2011-03-24 10:31:24.815429 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) Running State Change<br>
CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.817284 [DEBUG] switch_core_state_machine.c:360<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State CONSUME_MEDIA<br>
2011-03-24 10:31:24.817284 [DEBUG] switch_core_state_machine.c:360<br>
(sofia/internal/<a href="http://sip:1002@192.168.2.13:5060" target="_blank">sip:1002@192.168.2.13:5060</a>) State CONSUME_MEDIA going<br>
to sleep<br>
2011-03-24 10:31:24.819480 [DEBUG] switch_ivr_originate.c:2599 local<br>
variable string 0 = [presence_id=<a href="mailto:1003@microcomaustralia.com.au">1003@microcomaustralia.com.au</a>]<br>
2011-03-24 10:31:24.819480 [NOTICE] switch_channel.c:779 New Channel<br>
sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a><br>
[644a2402-7658-4831-8599-2439dc82e1f2]<br>
2011-03-24 10:31:24.850900 [DEBUG] mod_sofia.c:3920<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State Change CS_NEW -><br>
CS_INIT<br>
2011-03-24 10:31:24.851903 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> [BREAK]<br>
2011-03-24 10:31:24.865923 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) Running State Change<br>
CS_INIT<br>
2011-03-24 10:31:24.865923 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State INIT<br>
2011-03-24 10:31:24.872367 [DEBUG] mod_sofia.c:83<br>
sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> SOFIA INIT<br>
2011-03-24 10:31:24.897626 [DEBUG] mod_sofia.c:123<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State Change CS_INIT -><br>
CS_ROUTING<br>
2011-03-24 10:31:24.898904 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> [BREAK]<br>
2011-03-24 10:31:24.898904 [DEBUG] sofia.c:4402 Channel<br>
sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> entering state [calling][0]<br>
2011-03-24 10:31:24.899882 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State INIT going to sleep<br>
2011-03-24 10:31:24.899882 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) Running State Change<br>
CS_ROUTING<br>
2011-03-24 10:31:24.920400 [DEBUG] sofia.c:4402 Channel<br>
sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> entering state [calling][0]<br>
2011-03-24 10:31:24.930315 [DEBUG] sofia.c:6117 IP 59.167.180.194<br>
Rejected by acl "domains". Falling back to Digest auth.<br>
2011-03-24 10:31:24.930315 [NOTICE] switch_channel.c:779 New Channel<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a><br>
[294c0493-b397-481a-ac78-09fa727d79b9]<br>
2011-03-24 10:31:24.939488 [DEBUG] switch_channel.c:1512<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) Callstate Change DOWN -><br>
RINGING<br>
2011-03-24 10:31:24.947209 [DEBUG] switch_core_state_machine.c:341<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State ROUTING<br>
2011-03-24 10:31:24.947209 [DEBUG] mod_sofia.c:146<br>
sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> SOFIA ROUTING<br>
2011-03-24 10:31:24.949210 [DEBUG] switch_ivr_originate.c:66<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State Change CS_ROUTING -><br>
CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.950890 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a> [BREAK]<br>
2011-03-24 10:31:24.950890 [DEBUG] switch_core_state_machine.c:341<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State ROUTING going to<br>
sleep<br>
2011-03-24 10:31:24.950890 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) Running State Change<br>
CS_CONSUME_MEDIA<br>
2011-03-24 10:31:24.954269 [DEBUG] switch_core_state_machine.c:360<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State CONSUME_MEDIA<br>
2011-03-24 10:31:24.954269 [DEBUG] switch_core_state_machine.c:360<br>
(sofia/internal/<a href="http://sip:1003@192.168.2.13:5061" target="_blank">sip:1003@192.168.2.13:5061</a>) State CONSUME_MEDIA going<br>
to sleep<br>
2011-03-24 10:31:24.954269 [DEBUG] switch_ivr_originate.c:2599 local<br>
variable string 0 = [presence_id=<a href="mailto:1004@microcomaustralia.com.au">1004@microcomaustralia.com.au</a>]<br>
2011-03-24 10:31:24.960337 [NOTICE] switch_channel.c:779 New Channel<br>
sofia/internal/<a href="mailto:sip%3A1004@192.168.2.16">sip:1004@192.168.2.16</a><br>
[55c3e984-ddf8-45db-a157-65c50e18c8d0]<br>
2011-03-24 10:31:24.970358 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) Running State Change CS_NEW<br>
2011-03-24 10:31:24.970358 [DEBUG] switch_core_state_machine.c:320<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State NEW<br>
2011-03-24 10:31:24.994428 [DEBUG] mod_sofia.c:3920<br>
(sofia/internal/<a href="mailto:sip%3A1004@192.168.2.16">sip:1004@192.168.2.16</a>) State Change CS_NEW -> CS_INIT<br>
2011-03-24 10:31:24.996392 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="mailto:sip%3A1004@192.168.2.16">sip:1004@192.168.2.16</a> [BREAK]<br>
2011-03-24 10:31:25.023275 [DEBUG] sofia.c:4402 Channel<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> entering state [received][100]<br>
2011-03-24 10:31:25.029365 [DEBUG] sofia.c:4413 Remote SDP:<br>
v=0<br>
o=FreeSWITCH 1300899030 1300899032 IN IP4 59.167.180.194<br>
s=FreeSWITCH<br>
c=IN IP4 59.167.180.194<br>
t=0 0<br>
m=audio 24054 RTP/AVP 8 115 107 0 101<br>
a=rtpmap:8 PCMA/8000<br>
a=rtpmap:115 G7221/32000<br>
a=fmtp:115 bitrate=48000<br>
a=rtpmap:107 G7221/16000<br>
a=fmtp:107 bitrate=32000<br>
a=rtpmap:0 PCMU/8000<br>
a=rtpmap:101 telephone-event/8000<br>
a=fmtp:101 0-16<br>
a=silenceSupp:off - - - -<br>
a=ptime:20<br>
<br>
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec<br>
Compare [PCMA:8:8000:20]/[G7221:115:32000:20]<br>
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec<br>
Compare [PCMA:8:8000:20]/[G7221:107:16000:20]<br>
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec<br>
Compare [PCMA:8:8000:20]/[PCMU:0:8000:20]<br>
2011-03-24 10:31:25.035447 [DEBUG] sofia_glue.c:3859 Audio Codec<br>
Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]<br>
2011-03-24 10:31:25.037256 [DEBUG] sofia_glue.c:2454 Set Codec<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> PCMA/8000 20 ms 160 samples<br>
2011-03-24 10:31:25.049229 [DEBUG] sofia_glue.c:3955 Set 2833 dtmf<br>
send/recv payload to 101<br>
2011-03-24 10:31:25.049229 [DEBUG] sofia.c:4573<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State Change CS_NEW -> CS_INIT<br>
2011-03-24 10:31:25.049229 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> [BREAK]<br>
2011-03-24 10:31:25.053356 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) Running State Change CS_INIT<br>
2011-03-24 10:31:25.053356 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State INIT<br>
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:83<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> SOFIA INIT<br>
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:123<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State Change CS_INIT -><br>
CS_ROUTING<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_core_session.c:1047 Send<br>
signal sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> [BREAK]<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:338<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State INIT going to sleep<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:314<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) Running State Change CS_ROUTING<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_channel.c:1512<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) Callstate Change DOWN -> RINGING<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:341<br>
(sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a>) State ROUTING<br>
2011-03-24 10:31:25.055393 [DEBUG] mod_sofia.c:146<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> SOFIA ROUTING<br>
2011-03-24 10:31:25.055393 [DEBUG] switch_core_state_machine.c:77<br>
sofia/internal/<a href="mailto:1004@59.167.180.194">1004@59.167.180.194</a> Standard ROUTING<br>
2011-03-24 10:31:25.055393 [INFO] mod_dialplan_xml.c:331 Processing<br>
Brian May <1004>->6201 in context public<br>
<br>
<br>
Something went wrong here. It starts processing 6201 as per normal.<br>
--<br>
Brian May <<a href="mailto:brian@microcomaustralia.com.au">brian@microcomaustralia.com.au</a>><br>
<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>
</blockquote></div><br></div>