[Freeswitch-users] Remote Extension Registered but can't make/receive any call

Karsten Horsmann khorsmann at gmail.com
Sat Aug 10 22:35:13 MSD 2013 

Hi,

successful registered users only means that your user/password in the phone
are the same as in the directory.

It not means your dialplan is correct.

it seems that the bridge target is not there, the cli told you INVALID_PROFILE
after tried to use "doublenat" profile.

Check your sip_profile.

And please use http://pastebin.freeswitch.org/ for logs (username/password
show up in the login window).




2013/8/10 crazygabry <crazygabry at gmail.com>

> Hello every body,
>
> i'm a new freepbx user and i'm trying to configured a freeswitch server
> hosted in the cloud.
> I can register my softphone but i can't do anything: when i try to make a
> call i receive an error from the CLI that says INVALID_PROFILE.
> Can someone help me?
>
> Thanks in advice
> crazygabry
>
> P.S. that's what i see on CLI ( XXX.XXX.XXX is my local ip and YYY.YYY.YYY
> is the freeswitch IP)
>
> 2013-08-09 22:28:10.070676 [NOTICE] switch_channel.c:1030 New Channel
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060
> [dc15c333-fa2c-4055-a56e-f466279c8aae]
> 2013-08-09 22:28:10.070676 [DEBUG] switch_core_session.c:999 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.070676 [DEBUG] switch_core_session.c:999 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.070676 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_NEW
> 2013-08-09 22:28:10.070676 [DEBUG] switch_core_state_machine.c:433
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State NEW
> 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5727 Channel
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 entering state [received][100]
> 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5740 Remote SDP:
> v=0
> o=3cxVCE 303008025 298674930 IN IP4 XXX.XXX.XXX.XXX
> s=3cxVCE Audio Call
> c=IN IP4 XXX.XXX.XXX.XXX
> t=0 0
> m=audio 40046 RTP/AVP 3 0 8 101
> a=rtpmap:3 GSM/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=ptime:20
> m=video 40004 RTP/AVP 34
> c=IN IP4 XXX.XXX.XXX.XXX
> a=rtpmap:34 H263/90000
> a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=1
>
> 2013-08-09 22:28:10.090709 [DEBUG] sofia.c:5954
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State Change CS_NEW -> CS_INIT
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_INIT
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:454
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State INIT
> 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:87
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 SOFIA INIT
> 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:127
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State Change CS_INIT ->
> CS_ROUTING
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:454
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State INIT going to sleep
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_ROUTING
> 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:2111
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Callstate Change DOWN ->
> RINGING
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:470
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State ROUTING
> 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:150
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 SOFIA ROUTING
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:117
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Standard ROUTING
> 2013-08-09 22:28:10.090709 [INFO] mod_dialplan_xml.c:558 Processing Gwen
> <1100>->1000 in context public
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 parsing
> [public->unloop]
> continue=false
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 parsing
> [public->outside_call] continue=true
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Absolute Condition
> [outside_call]
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Action
> set(outside_call=true)
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 parsing
> [public->call_debug] continue=true
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Regex (FAIL)
> [call_debug]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 parsing
> [public->public_extensions] continue=false
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Regex (PASS)
> [public_extensions] destination_number(1000) =~ /^(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Action
> bridge(sofia/doublenat/1000%172.29.5.7 )
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:167
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State Change CS_ROUTING ->
> CS_EXECUTE
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:470
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State ROUTING going to sleep
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_EXECUTE
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:477
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State EXECUTE
> 2013-08-09 22:28:10.090709 [DEBUG] mod_sofia.c:243
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 SOFIA EXECUTE
> 2013-08-09 22:28:10.090709 [DEBUG] switch_core_state_machine.c:209
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Standard EXECUTE
> EXECUTE sofia/external/1100 at YYY.YYY.YYY.YYY:9060 set(outside_call=true)
> 2013-08-09 22:28:10.090709 [DEBUG] mod_dptools.c:1393
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 SET [outside_call]=[true]
> EXECUTE sofia/external/1100 at YYY.YYY.YYY.YYY:9060 export(RFC2822_DATE=Fri,
> 09
> Aug 2013 22:28:10 +0000)
> 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:1222 EXPORT
> (export_vars) [RFC2822_DATE]=[Fri, 09 Aug 2013 22:28:10 +0000]
> EXECUTE sofia/external/1100 at YYY.YYY.YYY.YYY:9060
> bridge(sofia/doublenat/1000%172.29.5.7 )
> 2013-08-09 22:28:10.090709 [DEBUG] switch_channel.c:1176
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 EXPORTING[export_vars]
> [RFC2822_DATE]=[Fri, 09 Aug 2013 22:28:10 +0000] to event
> 2013-08-09 22:28:10.090709 [DEBUG] switch_ivr_originate.c:2060 Parsing
> global variables
> 2013-08-09 22:28:10.090709 [ERR] mod_sofia.c:5024 Invalid Profile
> 2013-08-09 22:28:10.090709 [NOTICE] mod_sofia.c:5325 Close Channel N/A
> [CS_NEW]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:568 ()
> Running State Change CS_DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (N/A)
> State DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:397 N/A SOFIA DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578 (N/A)
> State DESTROY going to sleep
> 2013-08-09 22:28:10.110663 [NOTICE] switch_ivr_originate.c:2661 Cannot
> create outgoing channel of type [sofia] cause: [INVALID_PROFILE]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_ivr_originate.c:3632 Originate
> Resulted in Error Cause: 611 [INVALID_PROFILE]
> 2013-08-09 22:28:10.110663 [INFO] mod_dptools.c:3192 Originate Failed.
> Cause: INVALID_PROFILE
> 2013-08-09 22:28:10.110663 [NOTICE] switch_channel.c:4573 Hangup
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [CS_EXECUTE] [INVALID_PROFILE]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_channel.c:3130 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [KILL]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:2740
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 skip receive message
> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:477
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State EXECUTE going to sleep
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_HANGUP
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:678
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State HANGUP
> 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:504 Channel
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 hanging up, cause:
> INVALID_PROFILE
> 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:638 Responding to INVITE
> with: 502
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:48
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Standard HANGUP, cause:
> INVALID_PROFILE
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:678
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State HANGUP going to sleep
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:689
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Callstate Change RINGING ->
> HANGUP
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:446
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State Change CS_HANGUP ->
> CS_REPORTING
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change
> CS_REPORTING
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:761
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State REPORTING
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:92
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Standard REPORTING, cause:
> INVALID_PROFILE
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:761
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State REPORTING going to sleep
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:440
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State Change CS_REPORTING ->
> CS_DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1334 Send signal
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [BREAK]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_session.c:1542 Session 26
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Locked, Waiting on external
> entities
> 2013-08-09 22:28:10.110663 [NOTICE] switch_core_session.c:1560 Session 26
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Ended
> 2013-08-09 22:28:10.110663 [NOTICE] switch_core_session.c:1564 Close
> Channel
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 [CS_DESTROY]
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:565
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Callstate Change HANGUP -> DOWN
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:568
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) Running State Change CS_DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] mod_sofia.c:397
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 SOFIA DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:99
> sofia/external/1100 at YYY.YYY.YYY.YYY:9060 Standard DESTROY
> 2013-08-09 22:28:10.110663 [DEBUG] switch_core_state_machine.c:578
> (sofia/external/1100 at YYY.YYY.YYY.YYY:9060) State DESTROY going to sleep
>
>
>
>
>
>
> --
> View this message in context:
> http://freeswitch-users.2379917.n2.nabble.com/Remote-Extension-Registered-but-can-t-make-receive-any-call-tp7593777.html
> Sent from the freeswitch-users mailing list archive at Nabble.com.
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>



-- 
Mit freundlichen Grüßen
*Karsten Horsmann*
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130810/5e50bd1c/attachment.html

Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users mailing list