[Freeswitch-users] My device does not ring!

12 Mar 2013


      Two extensions 401 and 403 are registered by Twinkle!
401 calls 403 but 403 does not ring and 401 does not listen ring back,
but FS thinks them ringing!
I had not this problem beforehand,
This server has two ethernet cards,
#1 for connecting to trunk
and #2 for connecting to local network.(I have no problem in network
routing and I've tested all things)
These two extensions are registered at local network (192.168.54.69)
What is the problem? My freeswitch log is below:

2013-03-12 13:56:51.741964 [NOTICE] switch_channel.c:968 New Channel
sofia/sipinterface_6/401@192.168.54.69[5ab2118c-8aff-11e2-bd72-4f1eb6844087]
2013-03-12 13:56:51.741964 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.741964 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.741964 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_NEW
2013-03-12 13:56:51.741964 [DEBUG] switch_core_state_machine.c:433
(sofia/sipinterface_6/401@192.168.54.69) State NEW
2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.761967 [DEBUG] sofia.c:1719 detaching session
5ab2118c-8aff-11e2-bd72-4f1eb6844087
2013-03-12 13:56:51.761967 [DEBUG] sofia.c:1811 Re-attaching to session
5ab2118c-8aff-11e2-bd72-4f1eb6844087
2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.781957 [DEBUG] sofia.c:5574 Channel
sofia/sipinterface_6/401@192.168.54.69 entering state [received][100]
2013-03-12 13:56:51.781957 [DEBUG] sofia.c:5585 Remote SDP:
v=0
o=twinkle 799456135 497926540 IN IP4 192.168.1.102
s=-
c=IN IP4 192.168.1.102
t=0 0
m=audio 8000 RTP/AVP 98 97 8 0 3 101
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:98:16000:20:0]/[G722:9:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:98:16000:20:0]/[PCMU:0:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:98:16000:20:0]/[PCMA:8:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:98:16000:20:0]/[GSM:3:8000:20:13200]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:97:8000:20:0]/[G722:9:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:97:8000:20:0]/[PCMU:0:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:97:8000:20:0]/[PCMA:8:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[speex:97:8000:20:0]/[GSM:3:8000:20:13200]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[PCMA:8:8000:20:64000]/[G722:9:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000]
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare
[PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:3093 Set Codec
sofia/sipinterface_6/401@192.168.54.69 PCMA/8000 20 ms 160 samples 64000
bits
2013-03-12 13:56:51.801956 [DEBUG] switch_core_codec.c:111
sofia/sipinterface_6/401@192.168.54.69 Original read codec set to PCMA:8
2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:5266 Set 2833 dtmf
send/recv payload to 101
2013-03-12 13:56:51.801956 [DEBUG] sofia.c:5818 (sofia/sipinterface_6/
401@192.168.54.69) State Change CS_NEW -> CS_INIT
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_INIT
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/401@192.168.54.69) State INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/
401@192.168.54.69 SOFIA INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:126 (sofia/sipinterface_6/
401@192.168.54.69) State Change CS_INIT -> CS_ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/401@192.168.54.69) State INIT going to sleep
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:2003
(sofia/sipinterface_6/401@192.168.54.69) Callstate Change DOWN -> RINGING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/401@192.168.54.69) State ROUTING
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/
401@192.168.54.69 SOFIA ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:117
sofia/sipinterface_6/401@192.168.54.69 Standard ROUTING
2013-03-12 13:56:51.801956 [INFO] mod_dialplan_xml.c:557 Processing Parsa
<401>->403 in context context_1
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->conditioning_callerid] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (PASS)
[conditioning_callerid] ${internal_caller_id_number}(401) =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(effective_caller_id_name=${internal_caller_id_name})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(effective_caller_id_number=${internal_caller_id_number})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->conditioning_callrecord] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Absolute Condition
[conditioning_callrecord]
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_TITLE=Recording ${destination_number} ${caller_id_number}
${strftime(%Y-%m-%d %H:%M)})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_COPYRIGHT=(c) 2010 VoIP, Inc.)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_SOFTWARE=blue.box)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_ARTIST=2600hz)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_COMMENT=Automatically recorded via FreeSWITCH with blue.box)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RECORD_STEREO=true)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->postroute_global] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Absolute Condition
[postroute_global]
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->preanswer_callrecord_outbound] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[preanswer_callrecord_outbound] ${callrecord_outbound}() =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_17] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_17] destination_number(403) =~ /^334$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_18] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_18] destination_number(403) =~ /^496$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_23] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_23] destination_number(403) =~ /^4101$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_13] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_13] destination_number(403) =~ /^288|223$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_25] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_25] destination_number(403) =~ /^422$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_27] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_27] destination_number(403) =~ /^0[^0][0-9]{9}$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_28] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_28] destination_number(403) =~ /^401$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_29] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_29] destination_number(403) =~ /^402$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_30] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (PASS)
[main_number_30] destination_number(403) =~ /^403$/ break=on-false
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(call_timeout=30)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(ringback=local_stream://moh)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
export(sip_callee_id_name=m.emami)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action
export(sip_callee_id_number=403)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action bridge(user/
403@192.168.54.69)
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action hangup()
Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing
[context_1->main_number_31] continue=true
Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL)
[main_number_31] destination_number(403) =~ /^497$/ break=on-false
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:167
(sofia/sipinterface_6/401@192.168.54.69) State Change CS_ROUTING ->
CS_EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/401@192.168.54.69) State ROUTING going to sleep
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:477
(sofia/sipinterface_6/401@192.168.54.69) State EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:242 sofia/sipinterface_6/
401@192.168.54.69 SOFIA EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:209
sofia/sipinterface_6/401@192.168.54.69 Standard EXECUTE
EXECUTE sofia/sipinterface_6/401@192.168.54.69set(effective_caller_id_name=Parsa
Moshrefi)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [effective_caller_id_name]=[Parsa Moshrefi]
EXECUTE sofia/sipinterface_6/401@192.168.54.69set(effective_caller_id_number=401)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [effective_caller_id_number]=[401]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_TITLE=Recording
403 401 2013-03-12 13:56)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_TITLE]=[Recording 403 401 2013-03-12 13:56]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_COPYRIGHT=(c)
2010 VoIP, Inc.)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_COPYRIGHT]=[(c) 2010 VoIP, Inc.]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_SOFTWARE=blue.box)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_SOFTWARE]=[blue.box]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_ARTIST=2600hz)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_ARTIST]=[2600hz]
EXECUTE sofia/sipinterface_6/401@192.168.54.69set(RECORD_COMMENT=Automatically
recorded via FreeSWITCH with blue.box)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_COMMENT]=[Automatically recorded via
FreeSWITCH with blue.box]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_DATE=2013-03-12
13:56)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_DATE]=[2013-03-12 13:56]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_STEREO=true)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RECORD_STEREO]=[true]
EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-spymap/401/5ab2118c-8aff-11e2-bd72-4f1eb6844087)
EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-last_dial/401/403)
EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-last_dial/global/5ab2118c-8aff-11e2-bd72-4f1eb6844087)
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RFC2822_DATE=Tue, 12 Mar
2013 13:56:51 )
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [RFC2822_DATE]=[Tue, 12 Mar 2013 13:56:51 ]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(call_timeout=30)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [call_timeout]=[30]
EXECUTE sofia/sipinterface_6/401@192.168.54.69set(ringback=local_stream://moh)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [ringback]=[local_stream://moh]
EXECUTE sofia/sipinterface_6/401@192.168.54.69set(transfer_ringback=local_stream://moh)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401@192.168.54.69 SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/sipinterface_6/401@192.168.54.69export(sip_callee_id_name=m.emami)
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [sip_callee_id_name]=[m.emami]
EXECUTE sofia/sipinterface_6/401@192.168.54.69export(sip_callee_id_number=403)
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [sip_callee_id_number]=[403]
EXECUTE sofia/sipinterface_6/401@192.168.54.69 bridge(user/403@192.168.54.69
)
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089
sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars]
[sip_callee_id_name]=[m.emami] to event
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089
sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars]
[sip_callee_id_number]=[403] to event
2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089
sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars]
[sip_callee_id_name]=[m.emami] to event
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089
sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars]
[sip_callee_id_number]=[403] to event
2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables
2013-03-12 13:56:51.801956 [DEBUG] switch_event.c:1608 Parsing variable
[presence_id]=[403@192.168.54.69]
2013-03-12 13:56:51.801956 [NOTICE] switch_channel.c:968 New Channel
sofia/sipinterface_6/sip:403@192.168.1.115[5abc3f36-8aff-11e2-bd8e-4f1eb6844087]
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:4961 (sofia/sipinterface_6/
sip:403@192.168.1.115) State Change CS_NEW -> CS_INIT
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_INIT
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/sip:403@192.168.1.115) State INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/
sip:403@192.168.1.115 SOFIA INIT
2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:2647 Local SDP:
v=0
o=FreeSWITCH 1363059707 1363059708 IN IP4 192.168.54.69
s=FreeSWITCH
c=IN IP4 192.168.54.69
t=0 0
m=audio 24304 RTP/AVP 8 9 0 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:126 (sofia/sipinterface_6/
sip:403@192.168.1.115) State Change CS_INIT -> CS_ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/sip:403@192.168.1.115) State INIT going to sleep
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:2003
(sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change DOWN ->
RINGING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/sip:403@192.168.1.115) State ROUTING
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/
sip:403@192.168.1.115 SOFIA ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:67
(sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/sip:403@192.168.1.115) State ROUTING going to sleep
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change
CS_CONSUME_MEDIA
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:489
(sofia/sipinterface_6/sip:403@192.168.1.115) State CONSUME_MEDIA
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:489
(sofia/sipinterface_6/sip:403@192.168.1.115) State CONSUME_MEDIA going to
sleep
2013-03-12 13:56:51.801956 [DEBUG] sofia.c:5574 Channel
sofia/sipinterface_6/sip:403@192.168.1.115 entering state [calling][0]
2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:2994
(sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change RINGING ->
HANGUP
2013-03-12 13:57:21.001969 [NOTICE] switch_ivr_originate.c:3351 Hangup
sofia/sipinterface_6/sip:403@192.168.1.115 [CS_CONSUME_MEDIA] [NO_ANSWER]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_HANGUP
2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:3017 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [KILL]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:667
(sofia/sipinterface_6/sip:403@192.168.1.115) State HANGUP
2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel
sofia/sipinterface_6/sip:403@192.168.1.115 hanging up, cause: NO_ANSWER
2013-03-12 13:57:21.001969 [NOTICE] switch_ivr_originate.c:2608 Cannot
create outgoing channel of type [user] cause: [NO_ANSWER]
2013-03-12 13:57:21.001969 [DEBUG] switch_ivr_originate.c:3533 Originate
Resulted in Error Cause: 19 [NO_ANSWER]
2013-03-12 13:57:21.001969 [INFO] mod_dptools.c:3055 Originate Failed.
Cause: NO_ANSWER
EXECUTE sofia/sipinterface_6/401@192.168.54.69 hangup()
2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:2994
(sofia/sipinterface_6/401@192.168.54.69) Callstate Change RINGING -> HANGUP
2013-03-12 13:57:21.001969 [NOTICE] mod_dptools.c:1150 Hangup
sofia/sipinterface_6/401@192.168.54.69 [CS_EXECUTE] [NORMAL_CLEARING]
2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:3017 Send signal
sofia/sipinterface_6/401@192.168.54.69 [KILL]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:2689
sofia/sipinterface_6/401@192.168.54.69 skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:477
(sofia/sipinterface_6/401@192.168.54.69) State EXECUTE going to sleep
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_HANGUP
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:667
(sofia/sipinterface_6/401@192.168.54.69) State HANGUP
2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel
sofia/sipinterface_6/401@192.168.54.69 hanging up, cause: NORMAL_CLEARING
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:562 Sending CANCEL to
sofia/sipinterface_6/sip:403@192.168.1.115
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:48
sofia/sipinterface_6/sip:403@192.168.1.115 Standard HANGUP, cause: NO_ANSWER
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:667
(sofia/sipinterface_6/sip:403@192.168.1.115) State HANGUP going to sleep
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:446
(sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_HANGUP ->
CS_REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change
CS_REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749
(sofia/sipinterface_6/sip:403@192.168.1.115) State REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:92
sofia/sipinterface_6/sip:403@192.168.1.115 Standard REPORTING, cause:
NO_ANSWER
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749
(sofia/sipinterface_6/sip:403@192.168.1.115) State REPORTING going to sleep
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:440
(sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_REPORTING ->
CS_DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1499 Session 48
(sofia/sipinterface_6/sip:403@192.168.1.115) Locked, Waiting on external
entities
2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1517 Session 48
(sofia/sipinterface_6/sip:403@192.168.1.115) Ended
2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1521 Close
Channel sofia/sipinterface_6/sip:403@192.168.1.115 [CS_DESTROY]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:556
(sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change HANGUP -> DOWN
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:559
(sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569
(sofia/sipinterface_6/sip:403@192.168.1.115) State DESTROY
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/
sip:403@192.168.1.115 SOFIA DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:99
sofia/sipinterface_6/sip:403@192.168.1.115 Standard DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569
(sofia/sipinterface_6/sip:403@192.168.1.115) State DESTROY going to sleep
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:633 Responding to INVITE
with: 480
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:48
sofia/sipinterface_6/401@192.168.54.69 Standard HANGUP, cause:
NORMAL_CLEARING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:667
(sofia/sipinterface_6/401@192.168.54.69) State HANGUP going to sleep
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:446
(sofia/sipinterface_6/401@192.168.54.69) State Change CS_HANGUP ->
CS_REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749
(sofia/sipinterface_6/401@192.168.54.69) State REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:92
sofia/sipinterface_6/401@192.168.54.69 Standard REPORTING, cause:
NORMAL_CLEARING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749
(sofia/sipinterface_6/401@192.168.54.69) State REPORTING going to sleep
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:440
(sofia/sipinterface_6/401@192.168.54.69) State Change CS_REPORTING ->
CS_DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401@192.168.54.69 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1499 Session 47
(sofia/sipinterface_6/401@192.168.54.69) Locked, Waiting on external
entities
2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1517 Session 47
(sofia/sipinterface_6/401@192.168.54.69) Ended
2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1521 Close
Channel sofia/sipinterface_6/401@192.168.54.69 [CS_DESTROY]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:556
(sofia/sipinterface_6/401@192.168.54.69) Callstate Change HANGUP -> DOWN
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:559
(sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569
(sofia/sipinterface_6/401@192.168.54.69) State DESTROY
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/
401@192.168.54.69 SOFIA DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:99
sofia/sipinterface_6/401@192.168.54.69 Standard DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569
(sofia/sipinterface_6/401@192.168.54.69) State DESTROY going to sleep

[Freeswitch-users] My device does not ring!

Sayyed Mohammad Emami Razavi