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

crazygabry crazygabry at gmail.com
Sat Aug 10 02:32:05 MSD 2013 

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.

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