We've been through this before. Why are you on the public context with your internal extension? You should be on the default context. It's not doing anything because nothing is matching, and when that happens the call is hung up (with NORMAL CLEARNING).

-BDF

On Thu, Aug 23, 2012 at 10:56 AM, Ben Ringham <ben@fc-publishing.com> wrote:
Hello all,
Maybe you can help with an issue I have had from about day 2 of my fusion/freeswitch install. 

I am able to receive calls inbound to my softphone (counterpath eyebeam V1.5.19.4) When I try to dial out, or any extensions I am unable to connect. Watching the CLI it the softphone seems to connect and talk with freeswitch, then hangs up the call. Below is CLI of the call I am attempting. Any input to correct this issue will greatly help.
Ben

+OK log level  [7]
freeswitch@internal> 2012-08-23 10:45:42.332691 [DEBUG] sofia.c:6466 IP 10.0.1.151 Approved by acl "domains[]". Access Granted.
2012-08-23 10:45:42.333693 [NOTICE] switch_channel.c:812 New Channel sofia/internal/5555@10.0.1.162 [c915f249-a2d1-4c5e-8900-8ae47f3deea1]
2012-08-23 10:45:42.333693 [DEBUG] sofia.c:4744 Channel sofia/internal/5555@10.0.1.162 entering state [received][100]
2012-08-23 10:45:42.333693 [DEBUG] sofia.c:4755 Remote SDP:
v=0
o=- 7 2 IN IP4 10.0.1.151
s=CounterPath eyeBeam 1.5
c=IN IP4 10.0.1.151
t=0 0
m=audio 51938 RTP/AVP 107 0 8 18 101
a=rtpmap:107 BV32/16000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 3 : RQXbULH6 jeWr1bhp 10.0.1.151 51938
a=alt:2 2 : lIrXnsi1 yeNfshsQ 192.168.238.1 51938
a=alt:3 1 : np3FXIkK K342ICWN 192.168.64.1 51938

2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [BV32:107:16000:20:0]/[G722:9:8000:20:64000]
2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [BV32:107:16000:20:0]/[PCMU:0:8000:20:64000]
2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000]
2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [BV32:107:16000:20:0]/[GSM:3:8000:20:13200]
2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2012-08-23 10:45:42.333693 [DEBUG] sofia_glue.c:4619 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-08-23 10:45:42.334691 [DEBUG] sofia_glue.c:2760 Set Codec sofia/internal/5555@10.0.1.162 PCMU/8000 20 ms 160 samples 64000 bits
2012-08-23 10:45:42.334691 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_NEW
2012-08-23 10:45:42.334691 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/5555@10.0.1.162) State NEW
2012-08-23 10:45:42.334691 [DEBUG] sofia_glue.c:4733 Set 2833 dtmf send/recv payload to 101
2012-08-23 10:45:42.334691 [DEBUG] sofia.c:4922 (sofia/internal/5555@10.0.1.162) State Change CS_NEW -> CS_INIT
2012-08-23 10:45:42.334691 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_INIT
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/5555@10.0.1.162) State INIT
2012-08-23 10:45:42.335694 [DEBUG] mod_sofia.c:84 sofia/internal/5555@10.0.1.162 SOFIA INIT
2012-08-23 10:45:42.335694 [DEBUG] mod_sofia.c:124 (sofia/internal/5555@10.0.1.162) State Change CS_INIT -> CS_ROUTING
2012-08-23 10:45:42.335694 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/5555@10.0.1.162) State INIT going to sleep
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_ROUTING
2012-08-23 10:45:42.335694 [DEBUG] switch_channel.c:1664 (sofia/internal/5555@10.0.1.162) Callstate Change DOWN -> RINGING
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/5555@10.0.1.162) State ROUTING
2012-08-23 10:45:42.335694 [DEBUG] mod_sofia.c:147 sofia/internal/5555@10.0.1.162 SOFIA ROUTING
2012-08-23 10:45:42.335694 [DEBUG] switch_core_state_machine.c:77 sofia/internal/5555@10.0.1.162 Standard ROUTING
2012-08-23 10:45:42.335694 [INFO] mod_dialplan_xml.c:331 Processing Ben <5555>->18002267611 in context public
Dialplan: sofia/internal/5555@10.0.1.162 parsing [public->unloop] continue=false
Dialplan: sofia/internal/5555@10.0.1.162 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/5555@10.0.1.162 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/5555@10.0.1.162 parsing [public->outside_call] continue=true
Dialplan: sofia/internal/5555@10.0.1.162 Absolute Condition [outside_call]
Dialplan: sofia/internal/5555@10.0.1.162 Action set(outside_call=true)
Dialplan: sofia/internal/5555@10.0.1.162 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/5555@10.0.1.162 parsing [public->call_debug] continue=true
Dialplan: sofia/internal/5555@10.0.1.162 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/5555@10.0.1.162 parsing [public->public_extensions] continue=false
Dialplan: sofia/internal/5555@10.0.1.162 Regex (FAIL) [public_extensions] destination_number(18002267611) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/5555@10.0.1.162 parsing [public->inbound to ext 55] continue=false
Dialplan: sofia/internal/5555@10.0.1.162 Regex (PASS) [inbound to ext 55] context(public) =~ /public/ break=on-false
Dialplan: sofia/internal/5555@10.0.1.162 Regex (FAIL) [inbound to ext 55] destination_number(18002267611) =~ /4049371797/ break=on-false
2012-08-23 10:45:42.337693 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/5555@10.0.1.162) State Change CS_ROUTING -> CS_EXECUTE
2012-08-23 10:45:42.337693 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.337693 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/5555@10.0.1.162) State ROUTING going to sleep
2012-08-23 10:45:42.337693 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_EXECUTE
2012-08-23 10:45:42.337693 [DEBUG] switch_core_state_machine.c:366 (sofia/internal/5555@10.0.1.162) State EXECUTE
2012-08-23 10:45:42.337693 [DEBUG] mod_sofia.c:240 sofia/internal/5555@10.0.1.162 SOFIA EXECUTE
2012-08-23 10:45:42.337693 [DEBUG] switch_core_state_machine.c:157 sofia/internal/5555@10.0.1.162 Standard EXECUTE
EXECUTE sofia/internal/5555@10.0.1.162 set(outside_call=true)
2012-08-23 10:45:42.337693 [DEBUG] mod_dptools.c:1059 sofia/internal/5555@10.0.1.162 SET [outside_call]=[true]
EXECUTE sofia/internal/5555@10.0.1.162 set(RFC2822_DATE=Thu, 23 Aug 2012 10:45:42 +0530)
2012-08-23 10:45:42.338693 [DEBUG] mod_dptools.c:1059 sofia/internal/5555@10.0.1.162 SET [RFC2822_DATE]=[Thu, 23 Aug 2012 10:45:42 +0530]
2012-08-23 10:45:42.338693 [NOTICE] switch_core_state_machine.c:189 sofia/internal/5555@10.0.1.162 has executed the last dialplan instruction, hanging up.
2012-08-23 10:45:42.338693 [DEBUG] switch_channel.c:2559 (sofia/internal/5555@10.0.1.162) Callstate Change RINGING -> HANGUP
2012-08-23 10:45:42.338693 [NOTICE] switch_core_state_machine.c:191 Hangup sofia/internal/5555@10.0.1.162 [CS_EXECUTE] [NORMAL_CLEARING]
2012-08-23 10:45:42.338693 [DEBUG] switch_channel.c:2575 Send signal sofia/internal/5555@10.0.1.162 [KILL]
2012-08-23 10:45:42.338693 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.338693 [DEBUG] switch_core_state_machine.c:366 (sofia/internal/5555@10.0.1.162) State EXECUTE going to sleep
2012-08-23 10:45:42.338693 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_HANGUP
2012-08-23 10:45:42.339694 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/5555@10.0.1.162) State HANGUP
2012-08-23 10:45:42.339694 [DEBUG] mod_sofia.c:457 Channel sofia/internal/5555@10.0.1.162 hanging up, cause: NORMAL_CLEARING
2012-08-23 10:45:42.339694 [DEBUG] mod_sofia.c:519 Responding to INVITE with: 480
2012-08-23 10:45:42.340695 [DEBUG] switch_core_state_machine.c:46 sofia/internal/5555@10.0.1.162 Standard HANGUP, cause: NORMAL_CLEARING
2012-08-23 10:45:42.340695 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/5555@10.0.1.162) State HANGUP going to sleep
2012-08-23 10:45:42.340695 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/5555@10.0.1.162) State Change CS_HANGUP -> CS_REPORTING
2012-08-23 10:45:42.340695 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.340695 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/5555@10.0.1.162) Running State Change CS_REPORTING
2012-08-23 10:45:42.340695 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/5555@10.0.1.162) State REPORTING
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:53 sofia/internal/5555@10.0.1.162 Standard REPORTING, cause: NORMAL_CLEARING
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/5555@10.0.1.162) State REPORTING going to sleep
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/5555@10.0.1.162) State Change CS_REPORTING -> CS_DESTROY
2012-08-23 10:45:42.489418 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/5555@10.0.1.162 [BREAK]
2012-08-23 10:45:42.489418 [DEBUG] switch_core_session.c:1288 Session 22 (sofia/internal/5555@10.0.1.162) Locked, Waiting on external entities
2012-08-23 10:45:42.489418 [NOTICE] switch_core_session.c:1306 Session 22 (sofia/internal/5555@10.0.1.162) Ended
2012-08-23 10:45:42.489418 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/5555@10.0.1.162 [CS_DESTROY]
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/5555@10.0.1.162) Callstate Change HANGUP -> DOWN
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/5555@10.0.1.162) Running State Change CS_DESTROY
2012-08-23 10:45:42.489418 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/5555@10.0.1.162) State DESTROY
2012-08-23 10:45:42.491481 [DEBUG] mod_sofia.c:362 sofia/internal/5555@10.0.1.162 SOFIA DESTROY
2012-08-23 10:45:42.491481 [DEBUG] switch_core_state_machine.c:60 sofia/internal/5555@10.0.1.162 Standard DESTROY
2012-08-23 10:45:42.491481 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/5555@10.0.1.162) State DESTROY going to sleep


_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server
http://www.cudatel.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://wiki.freeswitch.org
http://www.cluecon.com

FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org




--
Brian D. Foster
Endigo Computer LLC
Email: bdfoster@endigotech.com
Phone: 317-800-7876
Indianapolis, Indiana, USA

This message contains confidential information and is intended for those listed in the "To:", "CC:", and/or "BCC:" fields of the message header. If you are not the intended recipient you are notified that disclosing, copying, distributing or taking any action in reliance on the contents of this information is strictly prohibited. E-mail transmission cannot be guaranteed to be secure or error-free as information could be intercepted, corrupted, lost, destroyed, arrive late or incomplete, or contain viruses. The sender therefore does not accept liability for any errors or omissions in the contents of this message, which arise as a result of e-mail transmission. If verification is required please request a hard-copy version.