[Freeswitch-users] My device does not ring!

Tue Mar 12 10:14:08 MSK 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.741964 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.741964 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401 at 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 at 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal
sofia/sipinterface_6/401 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.781957 [DEBUG] sofia.c:5574 Channel
sofia/sipinterface_6/401 at 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 at 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 at 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401 at 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 at 192.168.54.69) State INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/
401 at 192.168.54.69 SOFIA INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:126 (sofia/sipinterface_6/
401 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/401 at 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 at 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 at 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 at 192.168.54.69) State ROUTING
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/
401 at 192.168.54.69 SOFIA ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:117
sofia/sipinterface_6/401 at 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 at 192.168.54.69 parsing
[context_1->conditioning_callerid] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (PASS)
[conditioning_callerid] ${internal_caller_id_number}(401) =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(effective_caller_id_name=${internal_caller_id_name})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(effective_caller_id_number=${internal_caller_id_number})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->conditioning_callrecord] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Absolute Condition
[conditioning_callrecord]
Dialplan: sofia/sipinterface_6/401 at 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 at 192.168.54.69 Action
set(RECORD_COPYRIGHT=(c) 2010 VoIP, Inc.)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RECORD_SOFTWARE=blue.box)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RECORD_ARTIST=2600hz)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RECORD_COMMENT=Automatically recorded via FreeSWITCH with blue.box)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RECORD_STEREO=true)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->postroute_global] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Absolute Condition
[postroute_global]
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->preanswer_callrecord_outbound] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[preanswer_callrecord_outbound] ${callrecord_outbound}() =~ /^.+$/
break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_17] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_17] destination_number(403) =~ /^334$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_18] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_18] destination_number(403) =~ /^496$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_23] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_23] destination_number(403) =~ /^4101$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_13] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_13] destination_number(403) =~ /^288|223$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_25] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_25] destination_number(403) =~ /^422$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_27] continue=true
Dialplan: sofia/sipinterface_6/401 at 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 at 192.168.54.69 parsing
[context_1->main_number_28] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_28] destination_number(403) =~ /^401$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_29] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (FAIL)
[main_number_29] destination_number(403) =~ /^402$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_30] continue=true
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Regex (PASS)
[main_number_30] destination_number(403) =~ /^403$/ break=on-false
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action set(call_timeout=30)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(ringback=local_stream://moh)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
export(sip_callee_id_name=m.emami)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action
export(sip_callee_id_number=403)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action bridge(user/
403 at 192.168.54.69)
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 Action hangup()
Dialplan: sofia/sipinterface_6/401 at 192.168.54.69 parsing
[context_1->main_number_31] continue=true
Dialplan: sofia/sipinterface_6/401 at 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/401 at 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 at 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 at 192.168.54.69) State EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:242 sofia/sipinterface_6/
401 at 192.168.54.69 SOFIA EXECUTE
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:209
sofia/sipinterface_6/401 at 192.168.54.69 Standard EXECUTE
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [effective_caller_id_name]=[Parsa Moshrefi]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [effective_caller_id_number]=[401]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RECORD_TITLE]=[Recording 403 401 2013-03-12 13:56]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RECORD_COPYRIGHT]=[(c) 2010 VoIP, Inc.]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RECORD_SOFTWARE]=[blue.box]
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69 set(RECORD_ARTIST=2600hz)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401 at 192.168.54.69 SET [RECORD_ARTIST]=[2600hz]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RECORD_COMMENT]=[Automatically recorded via
FreeSWITCH with blue.box]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RECORD_DATE]=[2013-03-12 13:56]
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69 set(RECORD_STEREO=true)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401 at 192.168.54.69 SET [RECORD_STEREO]=[true]
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69hash(insert/192.168.54.69-spymap/401/5ab2118c-8aff-11e2-bd72-4f1eb6844087)
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69hash(insert/192.168.54.69-last_dial/401/403)
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69hash(insert/192.168.54.69-last_dial/global/5ab2118c-8aff-11e2-bd72-4f1eb6844087)
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [RFC2822_DATE]=[Tue, 12 Mar 2013 13:56:51 ]
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69 set(call_timeout=30)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401 at 192.168.54.69 SET [call_timeout]=[30]
EXECUTE sofia/sipinterface_6/401 at 192.168.54.69set(ringback=local_stream://moh)
2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/
401 at 192.168.54.69 SET [ringback]=[local_stream://moh]
EXECUTE sofia/sipinterface_6/401 at 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 at 192.168.54.69 SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/sipinterface_6/401 at 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 at 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 at 192.168.54.69 bridge(user/403 at 192.168.54.69
)
2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089
sofia/sipinterface_6/401 at 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 at 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 at 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 at 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 at 192.168.54.69]
2013-03-12 13:56:51.801956 [NOTICE] switch_channel.c:968 New Channel
sofia/sipinterface_6/sip:403 at 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 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403 at 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 at 192.168.1.115) State INIT
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/
sip:403 at 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 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454
(sofia/sipinterface_6/sip:403 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403 at 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 at 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 at 192.168.1.115) State ROUTING
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/
sip:403 at 192.168.1.115 SOFIA ROUTING
2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:67
(sofia/sipinterface_6/sip:403 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470
(sofia/sipinterface_6/sip:403 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:667
(sofia/sipinterface_6/sip:403 at 192.168.1.115) State HANGUP
2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel
sofia/sipinterface_6/sip:403 at 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 at 192.168.54.69 hangup()
2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:2994
(sofia/sipinterface_6/401 at 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 at 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 at 192.168.54.69 [KILL]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:1291 Send signal
sofia/sipinterface_6/401 at 192.168.54.69 [BREAK]
2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:2689
sofia/sipinterface_6/401 at 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 at 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 at 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 at 192.168.54.69) State HANGUP
2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel
sofia/sipinterface_6/401 at 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 at 192.168.1.115
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:48
sofia/sipinterface_6/sip:403 at 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 at 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 at 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 at 192.168.1.115 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/sip:403 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.1.115) State DESTROY
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/
sip:403 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415
(sofia/sipinterface_6/401 at 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 at 192.168.54.69) State REPORTING
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:92
sofia/sipinterface_6/401 at 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 at 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 at 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 at 192.168.54.69 [BREAK]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1499 Session 47
(sofia/sipinterface_6/401 at 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 at 192.168.54.69) Ended
2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1521 Close
Channel sofia/sipinterface_6/401 at 192.168.54.69 [CS_DESTROY]
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:556
(sofia/sipinterface_6/401 at 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 at 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 at 192.168.54.69) State DESTROY
2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/
401 at 192.168.54.69 SOFIA DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:99
sofia/sipinterface_6/401 at 192.168.54.69 Standard DESTROY
2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569
(sofia/sipinterface_6/401 at 192.168.54.69) State DESTROY going to sleep
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130312/5855ea0b/attachment-0001.html 