[Freeswitch-users] Problem with Siemens A580 IP Phones

Sun Nov 15 11:07:43 PST 2009

I have the same phone and all works fine. Make sure you are setting DTMF to
RFC2833 on the phone config page.

This log is supposed to go on pastebin (http://pastebin.freeswitch.org), not
here.

Also, you are making a group call which makes you ring 2 endpoints at the
same time. Verify your dialplan and make sure that's what you need/want.

Regards,

JM

On Sun, Nov 15, 2009 at 3:42 PM, <vedamaker at netscape.net> wrote:

>
> I am FS beginner and I have a basic PBX setup using FS with the Siemens
> A580 IP Phones.  I thought everything was working fine since I could make
> and receive basic calls without any obvious issues.  However, recently I
> wanted to use more advanced functions in FS and discovered that I could not
> use any of DTMF based functions (e.g. call transfer/record) during calls
> with the Siemens IP phones.  The same functions work fine when I use a
> softphone.  So, I started looking at the log file and I think there is some
> problem between the Siemens IP phones and FS (log file attached below).  It
> seems that when a call comes in, FS calls the extensions and then the
> extensions send back confirmation and SIP status codes.  With softphone
> extensions, I see 180 (Ringing) and 200 (OK) as normal status.  However,
> with Siemens IP phone extensions, I see 480 (Temporarily Unavailable) which
> seems to cause FS to terminate the session.  So, FS log shows there is
> actually no active session which explains why it does not performs DTMF
> detection for the call session.  However, the call to Siemens IP phones
> actually continues with ringing when an extension handset answers the call
> is established with the caller with full voice communication.  I don't know
> how FS works but this seems very strange.  I would like to know how to get
> FS to work properly with Siemens IP phones including the DTMF functions
> during calls.  Any help would be appreciated.
>
>
> ----------------------------------------------
> 2009-11-14 09:35:43.942450 [NOTICE] switch_channel.c:602 New Channel
> sofia/internal/4155559999 at 192.168.1.254[22f8ee00-d144-11de-a41f-e5a6b5425f55]
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change CS_NEW
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:404
> (sofia/internal/4155559999 at 192.168.1.254) State NEW
> 2009-11-14 09:35:43.951943 [DEBUG] sofia.c:3289 Channel sofia/internal/
> 4155559999 at 192.168.1.254 entering state [received][100]
> 2009-11-14 09:35:43.951943 [DEBUG] sofia.c:3296 Remote SDP:
> v=0
> o=- 119640485 119640485 IN IP4 192.168.1.97
> s=-
> c=IN IP4 192.168.1.97
> t=0 0
> m=audio 16430 RTP/AVP 0 100 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:100 NSE/8000
> a=fmtp:100 192-193
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=ptime:20
>
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
> [PCMU:0:8000:20]/[G7221:115:32000:20]
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
> [PCMU:0:8000:20]/[G7221:107:16000:20]
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
> [PCMU:0:8000:20]/[G722:9:8000:20]
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:3071 Audio Codec Compare
> [PCMU:0:8000:20]/[PCMU:0:8000:20]
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:2029 Set Codec
> sofia/internal/4155559999 at 192.168.1.254 PCMU/8000 20 ms 160 samples
> 2009-11-14 09:35:43.951943 [DEBUG] sofia_glue.c:3031 Set 2833 dtmf payload
> to 101
> 2009-11-14 09:35:43.951943 [DEBUG] sofia.c:3455 (sofia/internal/
> 4155559999 at 192.168.1.254) State Change CS_NEW -> CS_INIT
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change CS_INIT
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/4155559999 at 192.168.1.254) State INIT
> 2009-11-14 09:35:43.951943 [DEBUG] mod_sofia.c:83 sofia/internal/
> 4155559999 at 192.168.1.254 SOFIA INIT
> 2009-11-14 09:35:43.951943 [DEBUG] mod_sofia.c:111 (sofia/internal/
> 4155559999 at 192.168.1.254) State Change CS_INIT -> CS_ROUTING
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/4155559999 at 192.168.1.254) State INIT going to sleep
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change CS_ROUTING
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/4155559999 at 192.168.1.254) State ROUTING
> 2009-11-14 09:35:43.951943 [DEBUG] mod_sofia.c:130 sofia/internal/
> 4155559999 at 192.168.1.254 SOFIA ROUTING
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:78
> sofia/internal/4155559999 at 192.168.1.254 Standard ROUTING
> 2009-11-14 09:35:43.951943 [INFO] mod_dialplan_xml.c:315 Processing
> WIRELESS CALLER->4155553333 in context default
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->unloop] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->tod_example] continue=true
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [global-intercept] destination_number(4155553333) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [group-intercept] destination_number(4155553333) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->intercept-ext] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [intercept-ext] destination_number(4155553333) =~ /^\*\*(\d+)$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->redial] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [redial]
> destination_number(4155553333) =~ /^870$|^\*66$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->global] continue=true
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [global]
> ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
> break=never
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Absolute Condition
> [global]
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
>
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->snom-demo-2] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [snom-demo-2] destination_number(4155553333) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->snom-demo-1] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [snom-demo-1] destination_number(4155553333) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [eavesdrop]
> destination_number(4155553333) =~ /^88(.*)$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [eavesdrop]
> destination_number(4155553333) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->call_return] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [call_return] destination_number(4155553333) =~ /^\*69$|^869$|^lcr$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->del-group] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [del-group]
> destination_number(4155553333) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->add-group] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [add-group]
> destination_number(4155553333) =~ /^81(\d{2})$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->call-group-simo] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [call-group-simo] destination_number(4155553333) =~ /^82(\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->call-group-order] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [call-group-order] destination_number(4155553333) =~ /^83(\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->extension-intercom] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [extension-intercom] destination_number(4155553333) =~ /^8(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [Local_Extension] destination_number(4155553333) =~ /^(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->group_dial_ringables] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [group_dial_ringables] destination_number(4155553333) =~ /^1999$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->mobile_extensions] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [mobile_extensions] destination_number(4155553333) =~ /^(20[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->vmain]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [vmain]
> destination_number(4155553333) =~ /^vmain$|^4000$$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->vm1000] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [vm1000]
> destination_number(4155553333) =~ /^vm1000$|^4100$|^\*98$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->sip_uri] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [sip_uri]
> destination_number(4155553333) =~ /^sip:(.*)$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->nb_conferences] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [nb_conferences] destination_number(4155553333) =~ /^(30\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->wb_conferences] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [wb_conferences] destination_number(4155553333) =~ /^(31\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->uwb_conferences] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [uwb_conferences] destination_number(4155553333) =~ /^(32\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->cdquality_conferences] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [cdquality_conferences] destination_number(4155553333) =~ /^(33\d{2})$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->freeswitch_public_conf_via_sip] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [freeswitch_public_conf_via_sip] destination_number(4155553333) =~
> /^9(888|1616|3232)$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->mad_boss_intercom] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [mad_boss_intercom] destination_number(4155553333) =~ /^0911$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->mad_boss_intercom] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [mad_boss_intercom] destination_number(4155553333) =~ /^0912$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->mad_boss] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [mad_boss]
> destination_number(4155553333) =~ /^0913$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ivr_demo] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [ivr_demo]
> destination_number(4155553333) =~ /^5000$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->dynamic_conference] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [dynamic_conference] destination_number(4155553333) =~ /^5001$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->rtp_multicast_page] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [rtp_multicast_page] destination_number(4155553333) =~ /^pagegroup$|^7243$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [park]
> destination_number(4155553333) =~ /^5900$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->unpark] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [unpark]
> destination_number(4155553333) =~ /^5901$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS) [park]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [park]
> destination_number(4155553333) =~ /park\+(\d+)/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->unpark] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS) [unpark]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [unpark]
> destination_number(4155553333) =~ /^parking$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS) [park]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [park]
> destination_number(4155553333) =~ /callpark/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->unpark] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS) [unpark]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [unpark]
> destination_number(4155553333) =~ /pickup/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->wait]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [wait]
> destination_number(4155553333) =~ /^wait$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->fax_receive] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [fax_receive] destination_number(4155553333) =~ /^9978$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->fax_transmit] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [fax_transmit] destination_number(4155553333) =~ /^9979$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ringback_180] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [ringback_180] destination_number(4155553333) =~ /^9980$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ringback_183_uk_ring] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [ringback_183_uk_ring] destination_number(4155553333) =~ /^9981$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ringback_183_music_ring] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [ringback_183_music_ring] destination_number(4155553333) =~ /^9982$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ringback_post_answer_uk_ring] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [ringback_post_answer_uk_ring] destination_number(4155553333) =~ /^9983$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ringback_post_answer_music] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [ringback_post_answer_music] destination_number(4155553333) =~ /^9984$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->ClueCon] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [ClueCon]
> destination_number(4155553333) =~ /^9991$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->show_info] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [show_info]
> destination_number(4155553333) =~ /^9992$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->video_record] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [video_record] destination_number(4155553333) =~ /^9993$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->video_playback] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [video_playback] destination_number(4155553333) =~ /^9994$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->delay_echo] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [delay_echo] destination_number(4155553333) =~ /^9995$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->echo]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [echo]
> destination_number(4155553333) =~ /^9996$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->milliwatt] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [milliwatt]
> destination_number(4155553333) =~ /^9997$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->tone_stream] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [tone_stream] destination_number(4155553333) =~ /^9998$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->zrtp_enrollement] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [zrtp_enrollement] destination_number(4155553333) =~ /^9787$/ break=on-false
>
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->hold_music] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [hold_music] destination_number(4155553333) =~ /^9999$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing [default->fax]
> continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [fax]
> destination_number(4155553333) =~ /^fax|9777$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->test-9555] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [test-9555]
> destination_number(4155553333) =~ /^9555$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->test-9666] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL) [test-9666]
> destination_number(4155553333) =~ /^9666$/ break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->pizza_demo] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (FAIL)
> [pizza_demo] destination_number(4155553333) =~ /^(pizza|74992)$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 parsing
> [default->Inbound-4155553333] continue=false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Regex (PASS)
> [Inbound-4155553333] destination_number(4155553333) =~ /^4155553333$/
> break=on-false
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action ring_ready()
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action bind_meta_app(1 b
> s execute_extension::dx XML features)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action bind_meta_app(2 b
> s
> record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
>
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action bind_meta_app(3 b
> s execute_extension::cf XML features)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> set(ringback=${us-ring})
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> set(transfer_ringback=local_stream://moh)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> set(call_timeout=28)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> set(hangup_after_bridge=true)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> set(continue_on_fail=true)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action
> bridge(${group_call(ringables@${domain_name})})
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action answer()
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action sleep(1000)
> Dialplan: sofia/internal/4155559999 at 192.168.1.254 Action voicemail(default
> ${domain_name} 1000)
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:114
> (sofia/internal/4155559999 at 192.168.1.254) State Change CS_ROUTING ->
> CS_EXECUTE
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/4155559999 at 192.168.1.254) State ROUTING going to sleep
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change CS_EXECUTE
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:491
> (sofia/internal/4155559999 at 192.168.1.254) State EXECUTE
> 2009-11-14 09:35:43.951943 [DEBUG] mod_sofia.c:173 sofia/internal/
> 4155559999 at 192.168.1.254 SOFIA EXECUTE
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_state_machine.c:151
> sofia/internal/4155559999 at 192.168.1.254 Standard EXECUTE
> EXECUTE sofia/internal/4155559999 at 192.168.1.254hash(insert/192.168.1.254-spymap/4155559999/22f8ee00-d144-11de-a41f-e5a6b5425f55)
>
> EXECUTE sofia/internal/4155559999 at 192.168.1.254hash(insert/192.168.1.254-last_dial/4155559999/4155553333)
> EXECUTE sofia/internal/4155559999 at 192.168.1.254hash(insert/192.168.1.254-last_dial/global/22f8ee00-d144-11de-a41f-e5a6b5425f55)
>
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 ring_ready()
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:415 sofia/internal/
> 4155559999 at 192.168.1.254 receive message [RINGING]
> 2009-11-14 09:35:43.951943 [NOTICE] mod_sofia.c:1449 Ring-Ready
> sofia/internal/4155559999 at 192.168.1.254!
> 2009-11-14 09:35:43.951943 [DEBUG] switch_core_session.c:630 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:43.951943 [NOTICE] mod_dptools.c:415 Ring Ready
> sofia/internal/4155559999 at 192.168.1.254!
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 bind_meta_app(1 b s
> execute_extension::dx XML features)
> 2009-11-14 09:35:43.951943 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 1
> execute_extension::dx XML features
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 bind_meta_app(2 b s
> record_session::/usr/local/freeswitch/recordings/4155559999.2009-11-14-09-35-43.wav)
>
> 2009-11-14 09:35:43.951943 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 2
> record_session::/usr/local/freeswitch/recordings/4155559999.2009-11-14-09-35-43.wav
>
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 bind_meta_app(3 b s
> execute_extension::cf XML features)
> 2009-11-14 09:35:43.951943 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 3
> execute_extension::cf XML features
> EXECUTE sofia/internal/4155559999 at 192.168.1.254set(ringback=%(2000,4000,440.0,480.0))
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:748 sofia/internal/
> 4155559999 at 192.168.1.254 SET [ringback]=[%(2000,4000,440.0,480.0)]
> EXECUTE sofia/internal/4155559999 at 192.168.1.254set(transfer_ringback=local_stream://moh)
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:748 sofia/internal/
> 4155559999 at 192.168.1.254 SET [transfer_ringback]=[local_stream://moh]
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 set(call_timeout=28)
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:748 sofia/internal/
> 4155559999 at 192.168.1.254 SET [call_timeout]=[28]
> EXECUTE sofia/internal/4155559999 at 192.168.1.254set(hangup_after_bridge=true)
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:748 sofia/internal/
> 4155559999 at 192.168.1.254 SET [hangup_after_bridge]=[true]
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 set(continue_on_fail=true)
>
> 2009-11-14 09:35:43.951943 [DEBUG] mod_dptools.c:748 sofia/internal/
> 4155559999 at 192.168.1.254 SET [continue_on_fail]=[true]
> 2009-11-14 09:35:43.966601 [DEBUG] sofia.c:3289 Channel sofia/internal/
> 4155559999 at 192.168.1.254 entering state [early][180]
> EXECUTE sofia/internal/4155559999 at 192.168.1.254 bridge([presence_id=
> 1011 at 192.168.1.254]sofia/internal/sip:1011 at 192.168.1.98:5872,[presence_id=
> 1012 at 192.168.1.254]sofia/internal/sip:1012 at 192.168.1.98:5872,[presence_id=
> 1014 at 192.168.1.254]sofia/internal/sip:1014 at 192.168.1.97:5060)
> 2009-11-14 09:35:43.986485 [NOTICE] switch_channel.c:602 New Channel
> sofia/internal/sip:1011 at 192.168.1.98:5872[22ff385a-d144-11de-a41f-e5a6b5425f55]
> 2009-11-14 09:35:43.986485 [DEBUG] mod_sofia.c:2811 (sofia/internal/
> sip:1011 at 192.168.1.98:5872) State Change CS_NEW -> CS_INIT
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.990495 [NOTICE] switch_channel.c:602 New Channel
> sofia/internal/sip:1012 at 192.168.1.98:5872[22ff6230-d144-11de-a41f-e5a6b5425f55]
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Running State Change CS_INIT
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State INIT
> 2009-11-14 09:35:43.990495 [DEBUG] mod_sofia.c:83 sofia/internal/
> sip:1011 at 192.168.1.98:5872 SOFIA INIT
> 2009-11-14 09:35:43.990495 [DEBUG] mod_sofia.c:111 (sofia/internal/
> sip:1011 at 192.168.1.98:5872) State Change CS_INIT -> CS_ROUTING
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State INIT going to sleep
> 2009-11-14 09:35:43.990495 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1011 at 192.168.1.98:5872 entering state [calling][0]
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Running State Change
> CS_ROUTING
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State ROUTING
> 2009-11-14 09:35:43.990495 [DEBUG] mod_sofia.c:130 sofia/internal/
> sip:1011 at 192.168.1.98:5872 SOFIA ROUTING
> 2009-11-14 09:35:43.990495 [DEBUG] switch_ivr_originate.c:63
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State Change CS_ROUTING ->
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State ROUTING going to sleep
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Running State Change
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State CONSUME_MEDIA
> 2009-11-14 09:35:43.990495 [DEBUG] mod_sofia.c:2811 (sofia/internal/
> sip:1012 at 192.168.1.98:5872) State Change CS_NEW -> CS_INIT
> 2009-11-14 09:35:43.990495 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.994449 [NOTICE] switch_channel.c:602 New Channel
> sofia/internal/sip:1014 at 192.168.1.97:5060[22fffdb2-d144-11de-a41f-e5a6b5425f55]
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Running State Change CS_INIT
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State INIT
> 2009-11-14 09:35:43.994449 [DEBUG] mod_sofia.c:83 sofia/internal/
> sip:1012 at 192.168.1.98:5872 SOFIA INIT
> 2009-11-14 09:35:43.994449 [DEBUG] mod_sofia.c:111 (sofia/internal/
> sip:1012 at 192.168.1.98:5872) State Change CS_INIT -> CS_ROUTING
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.994449 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1012 at 192.168.1.98:5872 entering state [calling][0]
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State INIT going to sleep
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Running State Change
> CS_ROUTING
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State ROUTING
> 2009-11-14 09:35:43.994449 [DEBUG] mod_sofia.c:130 sofia/internal/
> sip:1012 at 192.168.1.98:5872 SOFIA ROUTING
> 2009-11-14 09:35:43.994449 [DEBUG] switch_ivr_originate.c:63
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State Change CS_ROUTING ->
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State ROUTING going to sleep
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Running State Change
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State CONSUME_MEDIA
> 2009-11-14 09:35:43.994449 [DEBUG] mod_sofia.c:2811 (sofia/internal/
> sip:1014 at 192.168.1.97:5060) State Change CS_NEW -> CS_INIT
> 2009-11-14 09:35:43.994449 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [BREAK]
> 2009-11-14 09:35:43.998457 [DEBUG] switch_ivr_originate.c:1701
> sofia/internal/4155559999 at 192.168.1.254 receive message [PROGRESS]
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Running State Change CS_INIT
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State INIT
> 2009-11-14 09:35:43.998457 [DEBUG] mod_sofia.c:83 sofia/internal/
> sip:1014 at 192.168.1.97:5060 SOFIA INIT
> 2009-11-14 09:35:43.998457 [DEBUG] mod_sofia.c:111 (sofia/internal/
> sip:1014 at 192.168.1.97:5060) State Change CS_INIT -> CS_ROUTING
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [BREAK]
> 2009-11-14 09:35:43.998457 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1014 at 192.168.1.97:5060 entering state [calling][0]
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:481
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State INIT going to sleep
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Running State Change
> CS_ROUTING
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State ROUTING
> 2009-11-14 09:35:43.998457 [DEBUG] mod_sofia.c:130 sofia/internal/
> sip:1014 at 192.168.1.97:5060 SOFIA ROUTING
> 2009-11-14 09:35:43.998457 [DEBUG] switch_ivr_originate.c:63
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State Change CS_ROUTING ->
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [BREAK]
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:484
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State ROUTING going to sleep
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Running State Change
> CS_CONSUME_MEDIA
> 2009-11-14 09:35:43.998457 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State CONSUME_MEDIA
> 2009-11-14 09:35:43.998457 [INFO] switch_ivr_originate.c:1701 Sending early
> media
> 2009-11-14 09:35:44.2435 [DEBUG] sofia_glue.c:2263 AUDIO RTP
> [sofia/internal/4155559999 at 192.168.1.254] 192.168.1.254 port 31052 ->
> 192.168.1.97 port 16430 codec: 0 ms: 20
> 2009-11-14 09:35:44.2435 [DEBUG] switch_rtp.c:1138 Starting timer [soft]
> 160 bytes per 20ms
> 2009-11-14 09:35:44.6432 [INFO] mod_sofia.c:1506 Ring SDP:
> v=0
> o=FreeSWITCH 1258189091 1258189092 IN IP4 192.168.1.254
> s=FreeSWITCH
> c=IN IP4 192.168.1.254
> t=0 0
> m=audio 31052 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
>
> 2009-11-14 09:35:44.6432 [NOTICE] mod_sofia.c:1509 Pre-Answer
> sofia/internal/4155559999 at 192.168.1.254!
> 2009-11-14 09:35:44.6432 [DEBUG] sofia.c:3289 Channel sofia/internal/
> 4155559999 at 192.168.1.254 entering state [early][183]
> 2009-11-14 09:35:44.6432 [DEBUG] switch_core_session.c:630 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:44.6432 [DEBUG] switch_ivr_originate.c:1718 Raw Codec
> Activation Success L16 at 8000hz 1 channel 20ms
> 2009-11-14 09:35:44.6432 [DEBUG] switch_ivr_originate.c:1777 Play Ringback
> Tone [%(2000,4000,440.0,480.0)]
> 2009-11-14 09:35:44.18430 [DEBUG] switch_core_io.c:649 sofia/internal/
> 4155559999 at 192.168.1.254 receive message [TRANSCODING_NECESSARY]
> 2009-11-14 09:35:44.22473 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1014 at 192.168.1.97:5060 entering state [proceeding][180]
> 2009-11-14 09:35:44.22473 [NOTICE] sofia.c:3353 Ring-Ready sofia/internal/
> sip:1014 at 192.168.1.97:5060!
> 2009-11-14 09:35:52.326423 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1011 at 192.168.1.98:5872 entering state [terminated][480]
> 2009-11-14 09:35:52.326423 [NOTICE] sofia.c:3849 Hangup sofia/internal/
> sip:1011 at 192.168.1.98:5872 [CS_CONSUME_MEDIA] [NO_USER_RESPONSE]
> 2009-11-14 09:35:52.326423 [DEBUG] switch_channel.c:1683 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [KILL]
> 2009-11-14 09:35:52.326423 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State CONSUME_MEDIA going to
> sleep
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Running State Change CS_HANGUP
>
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State HANGUP
> 2009-11-14 09:35:52.330490 [DEBUG] mod_sofia.c:306 sofia/internal/
> sip:1011 at 192.168.1.98:5872 Overriding SIP cause 408 with 480 from the
> other leg
> 2009-11-14 09:35:52.330490 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
> sip:1011 at 192.168.1.98:5872 hanging up, cause: NO_USER_RESPONSE
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/sip:1011 at 192.168.1.98:5872 Standard HANGUP, cause:
> NO_USER_RESPONSE
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State HANGUP going to sleep
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:476
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State Change CS_HANGUP ->
> CS_REPORTING
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1011 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Running State Change
> CS_REPORTING
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State REPORTING
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/sip:1011 at 192.168.1.98:5872 Standard REPORTING, cause:
> NO_USER_RESPONSE
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State REPORTING going to sleep
>
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_state_machine.c:411
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State Change CS_REPORTING ->
> CS_DESTROY
> 2009-11-14 09:35:52.330490 [DEBUG] switch_core_session.c:1068 Session 542
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Locked, Waiting on external
> entities
> 2009-11-14 09:35:52.618414 [DEBUG] sofia.c:3289 Channel sofia/internal/
> sip:1012 at 192.168.1.98:5872 entering state [terminated][480]
> 2009-11-14 09:35:52.618414 [NOTICE] sofia.c:3849 Hangup sofia/internal/
> sip:1012 at 192.168.1.98:5872 [CS_CONSUME_MEDIA] [NO_USER_RESPONSE]
> 2009-11-14 09:35:52.618414 [DEBUG] switch_channel.c:1683 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [KILL]
> 2009-11-14 09:35:52.618414 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State CONSUME_MEDIA going to
> sleep
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Running State Change CS_HANGUP
>
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State HANGUP
> 2009-11-14 09:35:52.626426 [DEBUG] mod_sofia.c:306 sofia/internal/
> sip:1012 at 192.168.1.98:5872 Overriding SIP cause 408 with 480 from the
> other leg
> 2009-11-14 09:35:52.626426 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
> sip:1012 at 192.168.1.98:5872 hanging up, cause: NO_USER_RESPONSE
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/sip:1012 at 192.168.1.98:5872 Standard HANGUP, cause:
> NO_USER_RESPONSE
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State HANGUP going to sleep
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:476
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State Change CS_HANGUP ->
> CS_REPORTING
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1012 at 192.168.1.98:5872 [BREAK]
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Running State Change
> CS_REPORTING
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State REPORTING
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/sip:1012 at 192.168.1.98:5872 Standard REPORTING, cause:
> NO_USER_RESPONSE
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State REPORTING going to sleep
>
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_state_machine.c:411
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State Change CS_REPORTING ->
> CS_DESTROY
> 2009-11-14 09:35:52.626426 [DEBUG] switch_core_session.c:1068 Session 543
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Locked, Waiting on external
> entities
> 2009-11-14 09:35:59.778421 [DEBUG] sofia.c:3289 Channel sofia/internal/
> 4155559999 at 192.168.1.254 entering state [terminated][487]
> 2009-11-14 09:35:59.778421 [NOTICE] sofia.c:3849 Hangup sofia/internal/
> 4155559999 at 192.168.1.254 [CS_EXECUTE] [ORIGINATOR_CANCEL]
> 2009-11-14 09:35:59.778421 [DEBUG] switch_channel.c:1683 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [KILL]
> 2009-11-14 09:35:59.778421 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:59.798426 [NOTICE] switch_ivr_originate.c:1994 Hangup
> sofia/internal/sip:1014 at 192.168.1.97:5060 [CS_CONSUME_MEDIA]
> [ORIGINATOR_CANCEL]
> 2009-11-14 09:35:59.798426 [DEBUG] switch_channel.c:1683 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [KILL]
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [BREAK]
> 2009-11-14 09:35:59.798426 [DEBUG] switch_ivr_originate.c:2134 Originate
> Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
> 2009-11-14 09:35:59.798426 [NOTICE] switch_core_session.c:1086 Session 542
> (sofia/internal/sip:1011 at 192.168.1.98:5872) Ended
> 2009-11-14 09:35:59.798426 [NOTICE] switch_core_session.c:1088 Close
> Channel sofia/internal/sip:1011 at 192.168.1.98:5872 [CS_DESTROY]
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] mod_sofia.c:255 sofia/internal/
> sip:1011 at 192.168.1.98:5872 SOFIA DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/sip:1011 at 192.168.1.98:5872 Standard DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1011 at 192.168.1.98:5872) State DESTROY going to sleep
> 2009-11-14 09:35:59.798426 [NOTICE] switch_core_session.c:1086 Session 543
> (sofia/internal/sip:1012 at 192.168.1.98:5872) Ended
> 2009-11-14 09:35:59.798426 [NOTICE] switch_core_session.c:1088 Close
> Channel sofia/internal/sip:1012 at 192.168.1.98:5872 [CS_DESTROY]
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] mod_sofia.c:255 sofia/internal/
> sip:1012 at 192.168.1.98:5872 SOFIA DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/sip:1012 at 192.168.1.98:5872 Standard DESTROY
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1012 at 192.168.1.98:5872) State DESTROY going to sleep
> 2009-11-14 09:35:59.798426 [INFO] mod_dptools.c:2093 Originate Failed.
>  Cause: ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:491
> (sofia/internal/4155559999 at 192.168.1.254) State EXECUTE going to sleep
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change CS_HANGUP
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/4155559999 at 192.168.1.254) State HANGUP
> 2009-11-14 09:35:59.798426 [DEBUG] mod_sofia.c:306 sofia/internal/
> 4155559999 at 192.168.1.254 Overriding SIP cause 487 with 487 from the other
> leg
> 2009-11-14 09:35:59.798426 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
> 4155559999 at 192.168.1.254 hanging up, cause: ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/4155559999 at 192.168.1.254 Standard HANGUP, cause:
> ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.798426 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/4155559999 at 192.168.1.254) State HANGUP going to sleep
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:503
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State CONSUME_MEDIA going to
> sleep
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Running State Change CS_HANGUP
>
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State HANGUP
> 2009-11-14 09:35:59.810601 [DEBUG] mod_sofia.c:306 sofia/internal/
> sip:1014 at 192.168.1.97:5060 Overriding SIP cause 487 with 487 from the
> other leg
> 2009-11-14 09:35:59.810601 [DEBUG] mod_sofia.c:338 Channel sofia/internal/
> sip:1014 at 192.168.1.97:5060 hanging up, cause: ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.810601 [DEBUG] mod_sofia.c:406 Sending CANCEL to
> sofia/internal/sip:1014 at 192.168.1.97:5060
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/sip:1014 at 192.168.1.97:5060 Standard HANGUP, cause:
> ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State HANGUP going to sleep
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:476
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State Change CS_HANGUP ->
> CS_REPORTING
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/sip:1014 at 192.168.1.97:5060 [BREAK]
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Running State Change
> CS_REPORTING
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State REPORTING
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/sip:1014 at 192.168.1.97:5060 Standard REPORTING, cause:
> ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State REPORTING going to sleep
>
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:411
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State Change CS_REPORTING ->
> CS_DESTROY
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_session.c:1068 Session 544
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Locked, Waiting on external
> entities
> 2009-11-14 09:35:59.810601 [NOTICE] switch_core_session.c:1086 Session 544
> (sofia/internal/sip:1014 at 192.168.1.97:5060) Ended
> 2009-11-14 09:35:59.810601 [NOTICE] switch_core_session.c:1088 Close
> Channel sofia/internal/sip:1014 at 192.168.1.97:5060 [CS_DESTROY]
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State DESTROY
> 2009-11-14 09:35:59.810601 [DEBUG] mod_sofia.c:255 sofia/internal/
> sip:1014 at 192.168.1.97:5060 SOFIA DESTROY
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/sip:1014 at 192.168.1.97:5060 Standard DESTROY
> 2009-11-14 09:35:59.810601 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/sip:1014 at 192.168.1.97:5060) State DESTROY going to sleep
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:476
> (sofia/internal/4155559999 at 192.168.1.254) State Change CS_HANGUP ->
> CS_REPORTING
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_session.c:932 Send signal
> sofia/internal/4155559999 at 192.168.1.254 [BREAK]
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/4155559999 at 192.168.1.254) Running State Change
> CS_REPORTING
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/4155559999 at 192.168.1.254) State REPORTING
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/4155559999 at 192.168.1.254 Standard REPORTING, cause:
> ORIGINATOR_CANCEL
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:612
> (sofia/internal/4155559999 at 192.168.1.254) State REPORTING going to sleep
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:411
> (sofia/internal/4155559999 at 192.168.1.254) State Change CS_REPORTING ->
> CS_DESTROY
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_session.c:1068 Session 541
> (sofia/internal/4155559999 at 192.168.1.254) Locked, Waiting on external
> entities
> 2009-11-14 09:35:59.814986 [NOTICE] switch_core_session.c:1086 Session 541
> (sofia/internal/4155559999 at 192.168.1.254) Ended
> 2009-11-14 09:35:59.814986 [NOTICE] switch_core_session.c:1088 Close
> Channel sofia/internal/4155559999 at 192.168.1.254 [CS_DESTROY]
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/4155559999 at 192.168.1.254) State DESTROY
> 2009-11-14 09:35:59.814986 [DEBUG] mod_sofia.c:255 sofia/internal/
> 4155559999 at 192.168.1.254 SOFIA DESTROY
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/4155559999 at 192.168.1.254 Standard DESTROY
> 2009-11-14 09:35:59.814986 [DEBUG] switch_core_state_machine.c:564
> (sofia/internal/4155559999 at 192.168.1.254) State DESTROY going to sleep
> _______________________________________________
> 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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20091115/7bad9a71/attachment-0002.html 