[Freeswitch-users] My device does not ring!
Michael Collins
msc at freeswitch.org
Wed Mar 13 00:01:36 MSK 2013
Could you put this into a pastebin entry? Also, for completeness, could you
enable sip trace as well? That will probably have all the info you need to
figure out what's happening. Be sure to use FreeSWITCH Log for the syntax
highlighting so that these old eyes can more easily see what's going on.
Thanks!
-MC
On Tue, Mar 12, 2013 at 12:14 AM, Sayyed Mohammad Emami Razavi <
emamirazavi at gmail.com> wrote:
> 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.69set(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
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
--
Michael S Collins
Twitter: @mercutioviz
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130312/d6b710ad/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list