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