Internal Extensions not working
151 views
Skip to first unread message
Rizwan Syed
May 25, 2012, 9:00:46 PM5/25/12
to 2600hz-dev
This is my first time playing with any VOIP PBX so please excuse me if
i ask dumb question
I have setup a internal ext (number 2000) now whenever a call come the
system recives it and play the auto attendants but if i press 1 to
goto that extension it goes straight to voice mail . Here is the log
which i get
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/sip:user1@<my public address>:5070) Running
State Change CS_CONSUME_MEDIA
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:429
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State
CONSUME_MEDIA
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:429
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State
CONSUME_MEDIA going to sleep
2012-05-26 00:08:20.667772 [DEBUG] sofia.c:5494 Channel sofia/
sipinterface_1/sip:user1@<my public address>:5070 entering state
[calling][0]
2012-05-26 00:08:20.667772 [ERR] sofia_reg.c:2195 Cannot locate any
authentication credentials to complete an authentication request for
realm '"<my public address>"'
2012-05-26 00:08:20.667772 [DEBUG] switch_channel.c:2846 (sofia/
sipinterface_1/sip:user1@<my public address>:5070) Callstate Change
RINGING -> HANGUP
2012-05-26 00:08:20.667772 [NOTICE] sofia_reg.c:2215 Hangup sofia/
sipinterface_1/sip:user1@<my public address>:5070 [CS_CONSUME_MEDIA]
[MANDATORY_IE_MISSING]
2012-05-26 00:08:20.667772 [DEBUG] switch_channel.c:2869 Send signal
sofia/sipinterface_1/sip:user1@<my public address>:5070 [KILL]
2012-05-26 00:08:20.667772 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/sip:user1@<my public address>:5070 [BREAK]
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/sip:user1@<my public address>:5070) Running
State Change CS_HANGUP
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State HANGUP
similarly if i make call from my soft phone it get disconnect right
away and here is the log which i get
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:7523 IP 192.168.0.12
Rejected by acl "net_list_5". Falling back to Digest auth.
2012-05-26 00:43:44.682300 [WARNING] sofia_reg.c:1445 SIP auth
challenge (INVITE) on sofia profile 'sipinterface_1' for
[41672...@192.168.0.13] from ip 192.168.0.12
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:7523 IP 192.168.0.12
Rejected by acl "net_list_5". Falling back to Digest auth.
2012-05-26 00:43:44.682300 [NOTICE] switch_channel.c:924 New Channel
sofia/sipinterface_1/us...@192.168.0.13 [9688ac85-3067-42cb-ba7b-
ee33db4e735f]
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5494 Channel sofia/
sipinterface_1/us...@192.168.0.13 entering state [received][100]
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5505 Remote SDP:
v=0
o=NCHSoftware-Talk 1337989944 1337989956 IN IP4 (IP address)
s=Express Talk Call
c=IN IP4 (IP address)
t=0 0
m=audio 8000 RTP/AVP 0 8 96 3 13 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:3 GSM/8000
a=rtpmap:13 CN/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=local:192.168.0.12 10000
a=domain:(IP address)
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:2919 Set Codec sofia/
sipinterface_1/us...@192.168.0.13 PCMU/8000 20 ms 160 samples 64000
bits
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4919 Set 2833 dtmf
send/recv payload to 101
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5717 (sofia/sipinterface_1/
us...@192.168.0.13) State Change CS_NEW -> CS_INIT
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change CS_INIT
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:401
(sofia/sipinterface_1/us...@192.168.0.13) State INIT
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:85 sofia/sipinterface_1/
us...@192.168.0.13 SOFIA INIT
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:125 (sofia/
sipinterface_1/us...@192.168.0.13) State Change CS_INIT -> CS_ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:401
(sofia/sipinterface_1/us...@192.168.0.13) State INIT going to sleep
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_channel.c:1884 (sofia/
sipinterface_1/us...@192.168.0.13) Callstate Change DOWN -> RINGING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:410
(sofia/sipinterface_1/us...@192.168.0.13) State ROUTING
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:148 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:104
sofia/sipinterface_1/us...@192.168.0.13 Standard ROUTING
2012-05-26 00:43:44.682300 [INFO] mod_dialplan_xml.c:481 Processing
2000 <user1>->4167230470 in context context_1
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>conditioning_callerid] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (PASS)
[conditioning_callerid] ${internal_caller_id_number}(2000) =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(effective_caller_id_name=${internal_caller_id_name})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(effective_caller_id_number=${internal_caller_id_number})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>postroute_global] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Absolute Condition
[postroute_global]
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-last_dial/global/${uuid})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_1] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_1] destination_number(4167230470) =~ /^2001$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_2] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_2] destination_number(4167230470) =~ /^2002$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_3] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_3] destination_number(4167230470) =~ /^2003$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_4] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_4] destination_number(4167230470) =~ /^2004$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_5] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_5] destination_number(4167230470) =~ /^2005$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_6] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_6] destination_number(4167230470) =~ /^2006$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_8] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_8] destination_number(4167230470) =~ /^2000$/ break=on-
false
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:154
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_ROUTING ->
CS_EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:410
(sofia/sipinterface_1/us...@192.168.0.13) State ROUTING going to sleep
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:417
(sofia/sipinterface_1/us...@192.168.0.13) State EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:241 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:192
sofia/sipinterface_1/us...@192.168.0.13 Standard EXECUTE
EXECUTE sofia/sipinterface_1/us...@192.168.0.13
set(effective_caller_id_name=Rizwan)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET
[effective_caller_id_name]=[Rizwan]
EXECUTE sofia/sipinterface_1/us...@192.168.0.13
set(effective_caller_id_number=2000)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET
[effective_caller_id_number]=[2000]
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-spymap/user1/9688ac85-3067-42cb-ba7b-ee33db4e735f)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-last_dial/user1/4167230470)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-last_dial/global/9688ac85-3067-42cb-ba7b-ee33db4e735f)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 set(RFC2822_DATE=Sat,
26 May 2012 00:43:44 -0700)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET [RFC2822_DATE]=[Sat, 26 May 2012
00:43:44 -0700]
2012-05-26 00:43:44.702299 [NOTICE] switch_core_state_machine.c:226
sofia/sipinterface_1/us...@192.168.0.13 has executed the last dialplan
instruction, hanging up.
2012-05-26 00:43:44.702299 [DEBUG] switch_channel.c:2846 (sofia/
sipinterface_1/us...@192.168.0.13) Callstate Change RINGING -> HANGUP
2012-05-26 00:43:44.702299 [NOTICE] switch_core_state_machine.c:228
Hangup sofia/sipinterface_1/us...@192.168.0.13 [CS_EXECUTE]
[NORMAL_CLEARING]
2012-05-26 00:43:44.702299 [DEBUG] switch_channel.c:2869 Send signal
sofia/sipinterface_1/us...@192.168.0.13 [KILL]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:417
(sofia/sipinterface_1/us...@192.168.0.13) State EXECUTE going to sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_HANGUP
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/us...@192.168.0.13) State HANGUP
2012-05-26 00:43:44.702299 [DEBUG] mod_sofia.c:469 Channel sofia/
sipinterface_1/us...@192.168.0.13 hanging up, cause: NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] mod_sofia.c:534 Responding to
INVITE with: 480
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:47
sofia/sipinterface_1/us...@192.168.0.13 Standard HANGUP, cause:
NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/us...@192.168.0.13) State HANGUP going to sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:393
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_HANGUP ->
CS_REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:662
(sofia/sipinterface_1/us...@192.168.0.13) State REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:79
sofia/sipinterface_1/us...@192.168.0.13 Standard REPORTING, cause:
NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:662
(sofia/sipinterface_1/us...@192.168.0.13) State REPORTING going to
sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:387
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_REPORTING ->
CS_DESTROY
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.722350 [DEBUG] switch_core_session.c:1380 Session
19 (sofia/sipinterface_1/us...@192.168.0.13) Locked, Waiting on
external entities
2012-05-26 00:43:44.722350 [NOTICE] switch_core_session.c:1398 Session
19 (sofia/sipinterface_1/us...@192.168.0.13) Ended
2012-05-26 00:43:44.722350 [NOTICE] switch_core_session.c:1400 Close
Channel sofia/sipinterface_1/us...@192.168.0.13 [CS_DESTROY]
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:491
(sofia/sipinterface_1/us...@192.168.0.13) Callstate Change HANGUP ->
DOWN
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:494
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:504
(sofia/sipinterface_1/us...@192.168.0.13) State DESTROY
2012-05-26 00:43:44.722350 [DEBUG] mod_sofia.c:374 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:86
sofia/sipinterface_1/us...@192.168.0.13 Standard DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:504
(sofia/sipinterface_1/us...@192.168.0.13) State DESTROY going to sleep
can anyone please help me understand what going wrong
i ask dumb question
I have setup a internal ext (number 2000) now whenever a call come the
system recives it and play the auto attendants but if i press 1 to
goto that extension it goes straight to voice mail . Here is the log
which i get
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/sip:user1@<my public address>:5070) Running
State Change CS_CONSUME_MEDIA
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:429
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State
CONSUME_MEDIA
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:429
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State
CONSUME_MEDIA going to sleep
2012-05-26 00:08:20.667772 [DEBUG] sofia.c:5494 Channel sofia/
sipinterface_1/sip:user1@<my public address>:5070 entering state
[calling][0]
2012-05-26 00:08:20.667772 [ERR] sofia_reg.c:2195 Cannot locate any
authentication credentials to complete an authentication request for
realm '"<my public address>"'
2012-05-26 00:08:20.667772 [DEBUG] switch_channel.c:2846 (sofia/
sipinterface_1/sip:user1@<my public address>:5070) Callstate Change
RINGING -> HANGUP
2012-05-26 00:08:20.667772 [NOTICE] sofia_reg.c:2215 Hangup sofia/
sipinterface_1/sip:user1@<my public address>:5070 [CS_CONSUME_MEDIA]
[MANDATORY_IE_MISSING]
2012-05-26 00:08:20.667772 [DEBUG] switch_channel.c:2869 Send signal
sofia/sipinterface_1/sip:user1@<my public address>:5070 [KILL]
2012-05-26 00:08:20.667772 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/sip:user1@<my public address>:5070 [BREAK]
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/sip:user1@<my public address>:5070) Running
State Change CS_HANGUP
2012-05-26 00:08:20.667772 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/sip:user1@<my public address>:5070) State HANGUP
similarly if i make call from my soft phone it get disconnect right
away and here is the log which i get
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:7523 IP 192.168.0.12
Rejected by acl "net_list_5". Falling back to Digest auth.
2012-05-26 00:43:44.682300 [WARNING] sofia_reg.c:1445 SIP auth
challenge (INVITE) on sofia profile 'sipinterface_1' for
[41672...@192.168.0.13] from ip 192.168.0.12
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:7523 IP 192.168.0.12
Rejected by acl "net_list_5". Falling back to Digest auth.
2012-05-26 00:43:44.682300 [NOTICE] switch_channel.c:924 New Channel
sofia/sipinterface_1/us...@192.168.0.13 [9688ac85-3067-42cb-ba7b-
ee33db4e735f]
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5494 Channel sofia/
sipinterface_1/us...@192.168.0.13 entering state [received][100]
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5505 Remote SDP:
v=0
o=NCHSoftware-Talk 1337989944 1337989956 IN IP4 (IP address)
s=Express Talk Call
c=IN IP4 (IP address)
t=0 0
m=audio 8000 RTP/AVP 0 8 96 3 13 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:3 GSM/8000
a=rtpmap:13 CN/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=local:192.168.0.12 10000
a=domain:(IP address)
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4798 Audio Codec
Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:2919 Set Codec sofia/
sipinterface_1/us...@192.168.0.13 PCMU/8000 20 ms 160 samples 64000
bits
2012-05-26 00:43:44.682300 [DEBUG] sofia_glue.c:4919 Set 2833 dtmf
send/recv payload to 101
2012-05-26 00:43:44.682300 [DEBUG] sofia.c:5717 (sofia/sipinterface_1/
us...@192.168.0.13) State Change CS_NEW -> CS_INIT
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change CS_INIT
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:401
(sofia/sipinterface_1/us...@192.168.0.13) State INIT
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:85 sofia/sipinterface_1/
us...@192.168.0.13 SOFIA INIT
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:125 (sofia/
sipinterface_1/us...@192.168.0.13) State Change CS_INIT -> CS_ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:401
(sofia/sipinterface_1/us...@192.168.0.13) State INIT going to sleep
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_channel.c:1884 (sofia/
sipinterface_1/us...@192.168.0.13) Callstate Change DOWN -> RINGING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:410
(sofia/sipinterface_1/us...@192.168.0.13) State ROUTING
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:148 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA ROUTING
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:104
sofia/sipinterface_1/us...@192.168.0.13 Standard ROUTING
2012-05-26 00:43:44.682300 [INFO] mod_dialplan_xml.c:481 Processing
2000 <user1>->4167230470 in context context_1
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>conditioning_callerid] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (PASS)
[conditioning_callerid] ${internal_caller_id_number}(2000) =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(effective_caller_id_name=${internal_caller_id_name})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(effective_caller_id_number=${internal_caller_id_number})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>postroute_global] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Absolute Condition
[postroute_global]
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action hash(insert/$
{domain_name}-last_dial/global/${uuid})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_1] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_1] destination_number(4167230470) =~ /^2001$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_2] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_2] destination_number(4167230470) =~ /^2002$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_3] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_3] destination_number(4167230470) =~ /^2003$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_4] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_4] destination_number(4167230470) =~ /^2004$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_5] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_5] destination_number(4167230470) =~ /^2005$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_6] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_6] destination_number(4167230470) =~ /^2006$/ break=on-
false
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 parsing [context_1-
>main_number_8] continue=true
Dialplan: sofia/sipinterface_1/us...@192.168.0.13 Regex (FAIL)
[main_number_8] destination_number(4167230470) =~ /^2000$/ break=on-
false
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:154
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_ROUTING ->
CS_EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:410
(sofia/sipinterface_1/us...@192.168.0.13) State ROUTING going to sleep
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:417
(sofia/sipinterface_1/us...@192.168.0.13) State EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] mod_sofia.c:241 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA EXECUTE
2012-05-26 00:43:44.682300 [DEBUG] switch_core_state_machine.c:192
sofia/sipinterface_1/us...@192.168.0.13 Standard EXECUTE
EXECUTE sofia/sipinterface_1/us...@192.168.0.13
set(effective_caller_id_name=Rizwan)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET
[effective_caller_id_name]=[Rizwan]
EXECUTE sofia/sipinterface_1/us...@192.168.0.13
set(effective_caller_id_number=2000)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET
[effective_caller_id_number]=[2000]
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-spymap/user1/9688ac85-3067-42cb-ba7b-ee33db4e735f)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-last_dial/user1/4167230470)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 hash(insert/
192.168.0.13-last_dial/global/9688ac85-3067-42cb-ba7b-ee33db4e735f)
EXECUTE sofia/sipinterface_1/us...@192.168.0.13 set(RFC2822_DATE=Sat,
26 May 2012 00:43:44 -0700)
2012-05-26 00:43:44.702299 [DEBUG] mod_dptools.c:1286 sofia/
sipinterface_1/us...@192.168.0.13 SET [RFC2822_DATE]=[Sat, 26 May 2012
00:43:44 -0700]
2012-05-26 00:43:44.702299 [NOTICE] switch_core_state_machine.c:226
sofia/sipinterface_1/us...@192.168.0.13 has executed the last dialplan
instruction, hanging up.
2012-05-26 00:43:44.702299 [DEBUG] switch_channel.c:2846 (sofia/
sipinterface_1/us...@192.168.0.13) Callstate Change RINGING -> HANGUP
2012-05-26 00:43:44.702299 [NOTICE] switch_core_state_machine.c:228
Hangup sofia/sipinterface_1/us...@192.168.0.13 [CS_EXECUTE]
[NORMAL_CLEARING]
2012-05-26 00:43:44.702299 [DEBUG] switch_channel.c:2869 Send signal
sofia/sipinterface_1/us...@192.168.0.13 [KILL]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:417
(sofia/sipinterface_1/us...@192.168.0.13) State EXECUTE going to sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_HANGUP
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/us...@192.168.0.13) State HANGUP
2012-05-26 00:43:44.702299 [DEBUG] mod_sofia.c:469 Channel sofia/
sipinterface_1/us...@192.168.0.13 hanging up, cause: NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] mod_sofia.c:534 Responding to
INVITE with: 480
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:47
sofia/sipinterface_1/us...@192.168.0.13 Standard HANGUP, cause:
NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:602
(sofia/sipinterface_1/us...@192.168.0.13) State HANGUP going to sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:393
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_HANGUP ->
CS_REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:362
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:662
(sofia/sipinterface_1/us...@192.168.0.13) State REPORTING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:79
sofia/sipinterface_1/us...@192.168.0.13 Standard REPORTING, cause:
NORMAL_CLEARING
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:662
(sofia/sipinterface_1/us...@192.168.0.13) State REPORTING going to
sleep
2012-05-26 00:43:44.702299 [DEBUG] switch_core_state_machine.c:387
(sofia/sipinterface_1/us...@192.168.0.13) State Change CS_REPORTING ->
CS_DESTROY
2012-05-26 00:43:44.702299 [DEBUG] switch_core_session.c:1180 Send
signal sofia/sipinterface_1/us...@192.168.0.13 [BREAK]
2012-05-26 00:43:44.722350 [DEBUG] switch_core_session.c:1380 Session
19 (sofia/sipinterface_1/us...@192.168.0.13) Locked, Waiting on
external entities
2012-05-26 00:43:44.722350 [NOTICE] switch_core_session.c:1398 Session
19 (sofia/sipinterface_1/us...@192.168.0.13) Ended
2012-05-26 00:43:44.722350 [NOTICE] switch_core_session.c:1400 Close
Channel sofia/sipinterface_1/us...@192.168.0.13 [CS_DESTROY]
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:491
(sofia/sipinterface_1/us...@192.168.0.13) Callstate Change HANGUP ->
DOWN
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:494
(sofia/sipinterface_1/us...@192.168.0.13) Running State Change
CS_DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:504
(sofia/sipinterface_1/us...@192.168.0.13) State DESTROY
2012-05-26 00:43:44.722350 [DEBUG] mod_sofia.c:374 sofia/
sipinterface_1/us...@192.168.0.13 SOFIA DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:86
sofia/sipinterface_1/us...@192.168.0.13 Standard DESTROY
2012-05-26 00:43:44.722350 [DEBUG] switch_core_state_machine.c:504
(sofia/sipinterface_1/us...@192.168.0.13) State DESTROY going to sleep
can anyone please help me understand what going wrong
Darren Schreiber
May 26, 2012, 3:19:16 AM5/26/12
to 2600h...@googlegroups.com
In the Number Manager section of blue.box you need to add your external
number, 416XXXXXXX and mark it as External. Looks like it is not marked
that way...
--
Darren Schreiber
CEO / Co-Founder
visit: www.2600hz.com <http://www.2600hz.com/>
sip:dar...@2600hz.com
tel: 415-886-7901
number, 416XXXXXXX and mark it as External. Looks like it is not marked
that way...
--
Darren Schreiber
CEO / Co-Founder
visit: www.2600hz.com <http://www.2600hz.com/>
sip:dar...@2600hz.com
tel: 415-886-7901
Reply all
Reply to author
Forward
0 new messages