[Freeswitch-users] Problem with Siemens A580 IP Phones

vedamaker at netscape.net vedamaker at netscape.net
Sun Nov 15 09:42:16 PST 2009


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.254
hash(insert/192.168.1.254-spymap/4155559999/22f8ee00-d144-11de-a41f-e5a6b5425f55)

EXECUTE sofia/internal/4155559999 at 192.168.1.254 hash(insert/192.168.1.254-last_dial/4155559999/4155553333)

EXECUTE sofia/internal/4155559999 at 192.168.1.254 hash(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.254 set(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.254 set(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.254 set(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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20091115/3f873e0d/attachment-0002.html 


More information about the FreeSWITCH-users mailing list