[Freeswitch-users] Possible registration/presence bug - Sometimes get "Originate Failed. Cause: USER_NOT_REGISTERED" when extension registration is present

Mon Apr 2 20:38:07 MSD 2012

plus the log is not detailed enough

sofia global siptrace on
sofia loglevel all 9
console loglevel debug (/log debug)

you would need enough log to cover the time when the phone is working
until when it stops working.

On Mon, Apr 2, 2012 at 11:35 AM, Anthony Minessale
<anthony.minessale at gmail.com> wrote:
> and use pastebin.freeswitch.org or attachments for logs imagine
> reading this from your mobile phone.
>
> On Mon, Apr 2, 2012 at 1:26 AM, Brian West <brian at freeswitch.org> wrote:
>> And use Jira to report bugs please.
>>
>> /b
>>
>> Sent from my iPhone
>>
>> On Apr 2, 2012, at 1:20 AM, Anton Kvashenkin <anton.jugatsu at gmail.com>
>> wrote:
>>
>> I think that the best way to check endpoints registrations is sofia status
>> profile internal reg. I have sometimes accuracy problems with show
>> registrations.
>>
>> 2 апреля 2012 г. 8:37 пользователь Phil Quesinberry
>> <philq at qsystemsengineering.com> написал:
>>>
>>> Hi,
>>>
>>> I've noticed what appears to be a bug which I wanted to bring to your
>>> attention.  Sometimes when FS is started, extensions can't be called even
>>> after they've registered.  This doesn't happen all the time... and restarting
>>> FS always solves the problem.  Just to be clear - this problem only
>>> sometimes occurs when FS has been started/restarted, like after an update.
>>> Once FS has "started successfully" and sees presence for registered
>>> extensions, it continues to work fine.
>>>
>>> It's all or nothing - no extensions can be dialed when this issue is
>>> present, whether they're local or NATted.  If one extension can be reached,
>>> you can reach them all (if they're registered, of course).
>>>
>>> See debug info below on an attempt to dial a local (no NAT) extension -
>>> this was one of the recent beta git pulls and the problem has been present
>>> through several updates.  Let me know if you need any additional info.
>>>
>>>
>>> freeswitch at internal> show registrations
>>>
>>>
>>> reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostname
>>>
>>>
>>> 102,192.168.1.6,a7289b6393a8023e,sofia/internal/sip:102 at 192.168.1.4:5060;transport=udp,1333338853,192.168.1.4,5060,udp,server.home
>>>
>>>
>>> 257,192.168.1.6,aab02ec49af03567,sofia/internal/sip:257 at 74.93.222.182:5060;transport=udp,1333338709,74.93.xx.xx,5060,udp,server.home
>>>
>>>
>>> 2001,192.168.1.6,bae1af9975ebfa50,sofia/internal/sip:2001 at 192.168.1.4:5060;transport=udp,1333338743,192.168.1.4,5060,udp,server.home
>>>
>>>
>>> 227,192.168.1.6,42db21f84f52e3ef,sofia/internal/sip:227 at 74.93.222.182:1066;transport=udp,1333338747,74.93.xx.xx,1066,udp,server.home
>>>
>>>
>>> 226,192.168.1.6,25619841fc53c75e,sofia/internal/sip:226 at 74.93.222.182:1068;transport=udp,1333338751,74.93.xx.xx,1068,udp,server.home
>>>
>>>
>>> 225,192.168.1.6,308cce2ca1734cdc,sofia/internal/sip:225 at 74.93.222.182:1067;transport=udp,1333338751,74.93.xx.xx,1067,udp,server.home
>>>
>>>
>>> 3900,192.168.1.6,54667b49ca74cabe,sofia/internal/sip:3900 at 173.66.100.94:54629;transport=udp;fs_nat=yes,1333338762,173.66.xx.xx,54629,udp,server.home
>>>
>>>
>>> 3901,192.168.1.6,6dc54f7994ffb61a,sofia/internal/sip:3901 at 173.66.100.94:6480;transport=udp;fs_nat=yes,1333338779,173.66.xx.xx,6480,udp,server.home
>>>
>>>
>>> 519,192.168.1.6,45249b30-85ddd13a at 10.0.0.159,sofia/internal/sip:519 at 74.93.222.182:1062,1333338779,74.93.xx.xx,1062,udp,server.home
>>>
>>> 9 total.
>>>
>>> 2012-04-01 23:50:41.449612 [DEBUG] sofia.c:7576 IP 192.168.1.4 Rejected by
>>> acl "domains". Falling back to Digest auth.
>>>
>>> 2012-04-01 23:50:41.449612 [WARNING] sofia_reg.c:1422 SIP auth challenge
>>> (INVITE) on sofia profile 'internal' for [2001 at 192.168.1.6] from ip
>>> 192.168.1.4
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:7576 IP 192.168.1.4 Rejected by
>>> acl "domains". Falling back to Digest auth.
>>>
>>> 2012-04-01 23:50:41.549553 [NOTICE] switch_channel.c:926 New Channel
>>> sofia/internal/102 at 192.168.1.6:5060 [9a9a3bde-116c-4100-b269-a6be7455c6c1]
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5541 Channel
>>> sofia/internal/102 at 192.168.1.6:5060 entering state [received][100]
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5552 Remote SDP:
>>>
>>> v=0
>>>
>>> o=MxSIP 0 1 IN IP4 192.168.1.4
>>>
>>> s=SIP Call
>>>
>>> c=IN IP4 192.168.1.4
>>>
>>> t=0 0
>>>
>>> m=audio 16384 RTP/AVP 0 110 8 9
>>>
>>> a=rtpmap:0 PCMU/8000
>>>
>>> a=rtpmap:110 PCMU/16000
>>>
>>> a=rtpmap:8 PCMA/8000
>>>
>>> a=rtpmap:9 G722/8000
>>>
>>> a=silenceSupp:off - - - -
>>>
>>> a=ptime:20
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5746
>>> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_NEW -> CS_INIT
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_INIT
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401
>>> (sofia/internal/102 at 192.168.1.6:5060) State INIT
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:85
>>> sofia/internal/102 at 192.168.1.6:5060 SOFIA INIT
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:125
>>> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_INIT -> CS_ROUTING
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401
>>> (sofia/internal/102 at 192.168.1.6:5060) State INIT going to sleep
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_ROUTING
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1886
>>> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change DOWN -> RINGING
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410
>>> (sofia/internal/102 at 192.168.1.6:5060) State ROUTING
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:148
>>> sofia/internal/102 at 192.168.1.6:5060 SOFIA ROUTING
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:104
>>> sofia/internal/102 at 192.168.1.6:5060 Standard ROUTING
>>>
>>> 2012-04-01 23:50:41.549553 [INFO] mod_dialplan_xml.c:485 Processing Phil
>>> <102>->2001 in context default
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->unloop]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unloop]
>>> ${unroll_loops}(true) =~ /^true$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unloop]
>>> ${sip_looped_call}() =~ /^true$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->call_direction] continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [call_direction] ${call_direction}() =~ /^(inbound|outbound|local)$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 ANTI-Action
>>> set(call_direction=local)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->tod_example] continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Date/TimeMatch (FAIL)
>>> [tod_example] break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->holiday_example] continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Date/TimeMatch (FAIL)
>>> [holiday_example] break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->group-intercept] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->redial]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [redial]
>>> destination_number(2001) =~ /^(redial|\*870)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->global]
>>> continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [global]
>>> ${call_debug}(false) =~ /^true$/ break=never
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [global]
>>> ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
>>> break=never
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Absolute Condition [global]
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-last_dial/global/${uuid})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->snom-demo-2] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [snom-demo-2]
>>> destination_number(2001) =~ /^\*9001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->snom-demo-1] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [snom-demo-1]
>>> destination_number(2001) =~ /^\*9000$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->call_privacy] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [call_privacy]
>>> destination_number(2001) =~ /^\*67(\d+)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->call_return] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [call_return]
>>> destination_number(2001) =~ /^\*69$|^869$|^lcr$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->del-group]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [del-group]
>>> destination_number(2001) =~ /^\*\*80(\d{2})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->add-group]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [add-group]
>>> destination_number(2001) =~ /^\*\*81(\d{2})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->call-group-simo] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [call-group-simo] destination_number(2001) =~ /^\*\*82(\d{2})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->call-group-order] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [call-group-order] destination_number(2001) =~ /^\*83(\d{2})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->intercept-ext] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [intercept-ext]
>>> destination_number(2001) =~ /^\*\*(\d+)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Local_Extension_Skinny] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [Local_Extension_Skinny] destination_number(2001) =~ /^(11[01][0-9])$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->send_to_voicemail] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,7})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->enum.9.10d] continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [enum.9.10d]
>>> destination_number(2001) =~ /^9(\d{10})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->enum.9.11d] continue=true
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [enum.9.11d]
>>> destination_number(2001) =~ /^9(\d{11})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->SipBroker.SIPDial] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [SipBroker.SIPDial] destination_number(2001) =~ /^([*]\d{5,})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->SipBroker.Toll_Free] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [SipBroker.Toll_Free] destination_number(2001) =~
>>> /^91?(8(00|66|77|88)[2-9]\d{6})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->TollFreeGateway] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [TollFreeGateway] destination_number(2001) =~
>>> /^91?(8(00|55|66|77|88)[2-9]\d{6})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->FlowRoute.91d10or11] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [FlowRoute.91d10or11] destination_number(2001) =~ /^91?(\d{10})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->HL7519.9.10d] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [HL7519.9.10d]
>>> caller_id_number(102) =~ /519/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->HL7519.9.11d] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [HL7519.9.11d]
>>> caller_id_number(102) =~ /519/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->HL7612.9.10d] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [HL7612.9.10d]
>>> ${toll_allow}(local,domestic) =~ /local/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [HL7612.9.10d]
>>> destination_number(2001) =~ /^9(\d{10})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->HL7612.9.11d] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [HL7612.9.11d]
>>> ${toll_allow}(local,domestic) =~ /local/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [HL7612.9.11d]
>>> destination_number(2001) =~ /^9(\d{11})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->enum.7d7]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [enum.7d7]
>>> destination_number(2001) =~ /^7(\d{7})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->xmpp.8d10]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [xmpp.8d10]
>>> destination_number(2001) =~ /^8(\d{10})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->xmpp.8d11]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [xmpp.8d11]
>>> destination_number(2001) =~ /^8(\d{11})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Talking
>>> Clock Time] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking Clock
>>> Time] destination_number(2001) =~ /^9170$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Talking
>>> Clock Date] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking Clock
>>> Date] destination_number(2001) =~ /^9171$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Talking
>>> Clock Date and Time] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking Clock
>>> Date and Time] destination_number(2001) =~ /^9172$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Recordings] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Recordings]
>>> destination_number(2001) =~ /^\*(732)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Company_Directory] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [Company_Directory] destination_number(2001) =~ /^5001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Hersch_Lauren_Main] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [Hersch_Lauren_Main] destination_number(2001) =~ /^5000$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Holiday_Announcement] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [Holiday_Announcement] destination_number(2001) =~ /^5010$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Ring all
>>> admin phones.park] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Ring all admin
>>> phones.park] destination_number(2001) =~ /^\*1001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Ring all
>>> admin phones] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Ring all admin
>>> phones] destination_number(2001) =~ /^1001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->group_dial_sales] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [group_dial_sales] destination_number(2001) =~ /^\*2000$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->group_dial_support] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [group_dial_support] destination_number(2001) =~ /^\*2001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->group_dial_billing] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [group_dial_billing] destination_number(2001) =~ /^\*2002$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->operator]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [operator]
>>> destination_number(2001) =~ /^operator$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->vmain]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain]
>>> destination_number(2001) =~ /^vmain$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->vmain1]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain1]
>>> destination_number(2001) =~ /^vmain1$|^\*97$|^\*4000$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->vmain2]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain2]
>>> destination_number(2001) =~ /^vmain2$|^\*98$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->sip_uri]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [sip_uri]
>>> destination_number(2001) =~ /^sip:(.*)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->nb_conferences] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [nb_conferences] destination_number(2001) =~ /^\*(30\d{2})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->wb_conferences] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [wb_conferences] destination_number(2001) =~ /^\*(31\d{2})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->uwb_conferences] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [uwb_conferences] destination_number(2001) =~ /^\*(32\d{2})$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->cdquality_conferences] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [cdquality_conferences] destination_number(2001) =~ /^\*(33\d{2})$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->freeswitch_public_conf_via_sip] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [freeswitch_public_conf_via_sip] destination_number(2001) =~
>>> /^\*9(888|8888|1616|3232)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->ivr_demo]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [ivr_demo]
>>> destination_number(2001) =~ /^\*5000$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->dynamic_conference] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [dynamic_conference] destination_number(2001) =~ /^\*5001$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->rtp_multicast_page] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [rtp_multicast_page] destination_number(2001) =~ /^pagegroup$|^\*7243$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->parking_slots] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [parking_slots]
>>> destination_number(2001) =~ /^(\*59[0-9][0-9])$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->valet_park_in] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [valet_park_in]
>>> destination_number(2001) =~ /^\*(6000)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->valet_park_out] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [valet_park_out] destination_number(2001) =~ /^\*(60\d\d)$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->park]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [park]
>>> source(mod_sofia) =~ /mod_sofia/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [park]
>>> destination_number(2001) =~ /park\+(\d+)/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->unpark]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unpark]
>>> source(mod_sofia) =~ /mod_sofia/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unpark]
>>> destination_number(2001) =~ /^parking$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->park]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [park]
>>> source(mod_sofia) =~ /mod_sofia/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [park]
>>> destination_number(2001) =~ /callpark/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->unpark]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unpark]
>>> source(mod_sofia) =~ /mod_sofia/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unpark]
>>> destination_number(2001) =~ /pickup/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->wait]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [wait]
>>> destination_number(2001) =~ /^wait$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->fax_receive] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [fax_receive]
>>> destination_number(2001) =~ /^\*9178$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->fax_transmit] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [fax_transmit]
>>> destination_number(2001) =~ /^\*9179$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->ringback_180] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [ringback_180]
>>> destination_number(2001) =~ /^\*9180$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->ringback_183_uk_ring] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [ringback_183_uk_ring] destination_number(2001) =~ /^\*9181$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->ringback_183_music_ring] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [ringback_183_music_ring] destination_number(2001) =~ /^\*9182$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->ringback_post_answer_uk_ring] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [ringback_post_answer_uk_ring] destination_number(2001) =~ /^\*9183$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->ringback_post_answer_music] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [ringback_post_answer_music] destination_number(2001) =~ /^\*9184$/
>>> break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->ClueCon]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [ClueCon]
>>> destination_number(2001) =~ /^\*9191$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->show_info]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [show_info]
>>> destination_number(2001) =~ /^\*9192$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->video_record] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [video_record]
>>> destination_number(2001) =~ /^\*9193$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->video_playback] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [video_playback] destination_number(2001) =~ /^\*9194$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->delay_echo] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [delay_echo]
>>> destination_number(2001) =~ /^\*9195$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->echo]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [echo]
>>> destination_number(2001) =~ /^\*9196$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->milliwatt]
>>> continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [milliwatt]
>>> destination_number(2001) =~ /^\*9197$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->tone_stream] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [tone_stream]
>>> destination_number(2001) =~ /^\*9198$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->zrtp_enrollement] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL)
>>> [zrtp_enrollement] destination_number(2001) =~ /^\*9787$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->hold_music] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [hold_music]
>>> destination_number(2001) =~ /^\*9664$/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing
>>> [default->Local_Extension] continue=false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS)
>>> [Local_Extension] destination_number(2001) =~ /(^\d{2,7}$)/ break=on-false
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(dialed_extension=2001)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> export(dialed_extension=2001)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action limit(db
>>> ${domain_name} 2001 ${limit_max} ${limit_destination})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(1 b s
>>> execute_extension::dx XML features)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(2 b s
>>> record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.wav)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(3 b s
>>> execute_extension::cf XML features)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(4 b s
>>> execute_extension::att_xfer XML features)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action set(ringback=%(2000,
>>> 4000, 440.0, 480.0))
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(transfer_ringback=%(2000, 4000, 440.0, 480.0))
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action set(call_timeout=24)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(hangup_after_bridge=true)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(continue_on_fail=true)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
>>> var callgroup)})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action
>>> bridge(user/${user_data(${destination_number}@${domain_name} attr
>>> id)}@${domain_name})
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action answer()
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action sleep(1000)
>>>
>>> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action voicemail(default
>>> ${domain_name} ${dialed_extension})
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:154
>>> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_ROUTING -> CS_EXECUTE
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410
>>> (sofia/internal/102 at 192.168.1.6:5060) State ROUTING going to sleep
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_EXECUTE
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:417
>>> (sofia/internal/102 at 192.168.1.6:5060) State EXECUTE
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:241
>>> sofia/internal/102 at 192.168.1.6:5060 SOFIA EXECUTE
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:192
>>> sofia/internal/102 at 192.168.1.6:5060 Standard EXECUTE
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(call_direction=local)
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [call_direction]=[local]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-spymap/102/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-last_dial/102/2001)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-last_dial/global/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(RFC2822_DATE=Sun, 01 Apr
>>> 2012 23:50:41 -0400)
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [RFC2822_DATE]=[Sun, 01 Apr 2012
>>> 23:50:41 -0400]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(dialed_extension=2001)
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [dialed_extension]=[2001]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 export(dialed_extension=2001)
>>>
>>> 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1093 EXPORT
>>> (export_vars) [dialed_extension]=[2001]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 limit(db 192.168.1.6 2001 5 )
>>>
>>> 2012-04-01 23:50:41.549553 [INFO] switch_limit.c:126 incr called:
>>> 192.168.1.6_2001 max:5, interval:0
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] mod_db.c:197 Usage for 192.168.1.6_2001
>>> is now 1/5
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(1 b s
>>> execute_extension::dx XML features)
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *1
>>> execute_extension::dx XML features
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(2 b s
>>> record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bde-116c-4100-b269-a6be7455c6c1.wav)
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *2
>>> record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bde-116c-4100-b269-a6be7455c6c1.wav
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(3 b s
>>> execute_extension::cf XML features)
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *3
>>> execute_extension::cf XML features
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(4 b s
>>> execute_extension::att_xfer XML features)
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: *4
>>> execute_extension::att_xfer XML features
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(ringback=%(2000, 4000,
>>> 440.0, 480.0))
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [ringback]=[%(2000, 4000, 440.0,
>>> 480.0)]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(transfer_ringback=%(2000,
>>> 4000, 440.0, 480.0))
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [transfer_ringback]=[%(2000, 4000,
>>> 440.0, 480.0)]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(call_timeout=24)
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [call_timeout]=[24]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(hangup_after_bridge=true)
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [hangup_after_bridge]=[true]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(continue_on_fail=true)
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [continue_on_fail]=[true]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-call_return/2001/102)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-last_dial_ext/2001/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(called_party_callgroup=)
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281
>>> sofia/internal/102 at 192.168.1.6:5060 SET [called_party_callgroup]=[UNDEF]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060
>>> hash(insert/192.168.1.6-last_dial//9a9a3bde-116c-4100-b269-a6be7455c6c1)
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bridge(user/2001 at 192.168.1.6)
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047
>>> sofia/internal/102 at 192.168.1.6:5060 EXPORTING[export_vars]
>>> [dialed_extension]=[2001] to event
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing
>>> global variables
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047
>>> sofia/internal/102 at 192.168.1.6:5060 EXPORTING[export_vars]
>>> [dialed_extension]=[2001] to event
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing
>>> global variables
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing variable
>>> [sip_invite_domain]=[192.168.1.6]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing variable
>>> [presence_id]=[2001 at 192.168.1.6]
>>>
>>> 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot
>>> create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 Originate
>>> Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
>>>
>>> 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot
>>> create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 Originate
>>> Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
>>>
>>> 2012-04-01 23:50:41.569549 [INFO] mod_dptools.c:2922 Originate Failed.
>>> Cause: USER_NOT_REGISTERED
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 answer()
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:4876 Audio Codec Compare
>>> [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:2996 Set Codec
>>> sofia/internal/102 at 192.168.1.6:5060 PCMU/8000 20 ms 160 samples 64000 bits
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_codec.c:111
>>> sofia/internal/102 at 192.168.1.6:5060 Original read codec set to PCMU:0
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:5008 No 2833 in SDP.
>>> Disable 2833 dtmf and switch to INFO
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:3248 AUDIO RTP
>>> [sofia/internal/102 at 192.168.1.6:5060] 192.168.1.6 port 23164 -> 192.168.1.4
>>> port 16384 codec: 0 ms: 20
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_rtp.c:1661 Starting timer [soft]
>>> 160 bytes per 20ms
>>>
>>> 2012-04-01 23:50:41.569549 [NOTICE] sofia_glue.c:4022 Pre-Answer
>>> sofia/internal/102 at 192.168.1.6:5060!
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:2932
>>> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change RINGING -> EARLY
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] mod_sofia.c:750 Local SDP
>>> sofia/internal/102 at 192.168.1.6:5060:
>>>
>>> v=0
>>>
>>> o=FreeSWITCH 1333315477 1333315478 IN IP4 192.168.1.6
>>>
>>> s=FreeSWITCH
>>>
>>> c=IN IP4 192.168.1.6
>>>
>>> t=0 0
>>>
>>> m=audio 23164 RTP/AVP 0
>>>
>>> a=rtpmap:0 PCMU/8000
>>>
>>> a=silenceSupp:off - - - -
>>>
>>> a=ptime:20
>>>
>>> a=sendrecv
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:731 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:3190
>>> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change EARLY -> ACTIVE
>>>
>>> 2012-04-01 23:50:41.569549 [NOTICE] mod_dptools.c:1135 Channel
>>> [sofia/internal/102 at 192.168.1.6:5060] has been answered
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:877 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.569549 [DEBUG] sofia.c:5541 Channel
>>> sofia/internal/102 at 192.168.1.6:5060 entering state [completed][200]
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 sleep(1000)
>>>
>>> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:41.669832 [DEBUG] sofia.c:5541 Channel
>>> sofia/internal/102 at 192.168.1.6:5060 entering state [ready][200]
>>>
>>> 2012-04-01 23:50:41.849781 [DEBUG] switch_rtp.c:3224 Correct ip/port
>>> confirmed.
>>>
>>> EXECUTE sofia/internal/102 at 192.168.1.6:5060 voicemail(default 192.168.1.6
>>> 2001)
>>>
>>> 2012-04-01 23:50:42.689527 [DEBUG] switch_ivr_play_say.c:1306 Codec
>>> Activated L16 at 8000hz 1 channels 20ms
>>>
>>> 2012-04-01 23:50:46.249491 [DEBUG] switch_core_session.c:877 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2848
>>> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change ACTIVE -> HANGUP
>>>
>>> 2012-04-01 23:50:46.269490 [NOTICE] sofia.c:628 Hangup
>>> sofia/internal/102 at 192.168.1.6:5060 [CS_EXECUTE] [NORMAL_CLEARING]
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2871 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [KILL]
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_ivr_play_say.c:1678 done playing
>>> file
>>> /usr/local/freeswitch/storage/voicemail/default/192.168.1.6/2001/greeting_1.wav
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:2287
>>> sofia/internal/102 at 192.168.1.6:5060 skip receive message
>>> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:417
>>> (sofia/internal/102 at 192.168.1.6:5060) State EXECUTE going to sleep
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_HANGUP
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602
>>> (sofia/internal/102 at 192.168.1.6:5060) State HANGUP
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] mod_sofia.c:469 Channel
>>> sofia/internal/102 at 192.168.1.6:5060 hanging up, cause: NORMAL_CLEARING
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:47
>>> sofia/internal/102 at 192.168.1.6:5060 Standard HANGUP, cause: NORMAL_CLEARING
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602
>>> (sofia/internal/102 at 192.168.1.6:5060) State HANGUP going to sleep
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:393
>>> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_HANGUP -> CS_REPORTING
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_REPORTING
>>>
>>> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:662
>>> (sofia/internal/102 at 192.168.1.6:5060) State REPORTING
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:79
>>> sofia/internal/102 at 192.168.1.6:5060 Standard REPORTING, cause:
>>> NORMAL_CLEARING
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:662
>>> (sofia/internal/102 at 192.168.1.6:5060) State REPORTING going to sleep
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:387
>>> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_REPORTING ->
>>> CS_DESTROY
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1182 Send signal
>>> sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1382 Session 13
>>> (sofia/internal/102 at 192.168.1.6:5060) Locked, Waiting on external entities
>>>
>>> 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1400 Session 13
>>> (sofia/internal/102 at 192.168.1.6:5060) Ended
>>>
>>> 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1402 Close
>>> Channel sofia/internal/102 at 192.168.1.6:5060 [CS_DESTROY]
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:491
>>> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change HANGUP -> DOWN
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:494
>>> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_DESTROY
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504
>>> (sofia/internal/102 at 192.168.1.6:5060) State DESTROY
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] mod_sofia.c:374
>>> sofia/internal/102 at 192.168.1.6:5060 SOFIA DESTROY
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:86
>>> sofia/internal/102 at 192.168.1.6:5060 Standard DESTROY
>>>
>>> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504
>>> (sofia/internal/102 at 192.168.1.6:5060) State DESTROY going to sleep
>>>
>>> freeswitch at internal> /bye
>>>
>>> [root at server bin]#
>>>
>>> Regards,
>>>
>>> Phil Quesinberry
>>>
>>> Q Systems Engineering, Inc.
>>>
>>> Electronic Controls and Embedded Systems Development
>>>
>>> (410) 969-8002
>>>
>>> http://www.qsystemsengineering.com
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> 
>> 
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> 
>> 
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>
>
>
> --
> Anthony Minessale II
>
> FreeSWITCH http://www.freeswitch.org/
> ClueCon http://www.cluecon.com/
> Twitter: http://twitter.com/FreeSWITCH_wire
>
> AIM: anthm
> MSN:anthony_minessale at hotmail.com
> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
> IRC: irc.freenode.net #freeswitch
>
> FreeSWITCH Developer Conference
> sip:888 at conference.freeswitch.org
> googletalk:conf+888 at conference.freeswitch.org
> pstn:+19193869900

-- 
Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm
MSN:anthony_minessale at hotmail.com
GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference
sip:888 at conference.freeswitch.org
googletalk:conf+888 at conference.freeswitch.org
pstn:+19193869900