[Freeswitch-users] Freeswitch User Adding

Sat May 11 19:33:15 MSD 2013

I cannot tell you why this is only a problem with extensions w/ 5 digits,
but I can tell you what failed here.  Your underlying error is:

2013-05-11 12:14:14.980444 [ERR] sofia_glue.c:4927 a=crypto in RTP/AVP,
refer to rfc3711

2013-05-11 12:14:14.980444 [ERR] mod_sofia.c:2789 CODEC NEGOTIATION ERROR.
SDP:

v=0

o=- 3577252345 3577252345 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4010 RTP/AVP 8 0 3 101

c=IN IP4 141.196.174.60

a=rtpmap:8 PCMA/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:3 GSM/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4011 IN IP4 192.168.43.10

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:fig56WojEoKmN07gnvdJZ9Mk6lznskMJszpBOqik

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:HUiy486/260zwSkQ0Z771fKC+g48P9cYEXNqlEYO

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:830 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_channel.c:2994
(sofia/internal/60021 at my.server.ip.address) Callstate Change RINGING ->
HANGUP                                           

2013-05-11 12:14:14.980444 [NOTICE] switch_channel.c:3216 Hangup
sofia/internal/60021 at my.server.ip.address [CS_EXECUTE]
[INCOMPATIBLE_DESTINATION]

Can you try it without the crypto stuff and paste the same output to
pastebin.freeswitch.org (not here in email)?

From: freeswitch-users-bounces at lists.freeswitch.org
[mailto:freeswitch-users-bounces at lists.freeswitch.org] On Behalf Of Burak
BorYazilim
Sent: Saturday, May 11, 2013 7:28 AM
To: FreeSWITCH Users Help
Subject: Re: [Freeswitch-users] Freeswitch User Adding

First off all thanks for your kind helps.

Let me tell you the situation more clearly.

Firstly I used Android phones as sip clients with the open source sip client
program, CSipSimple. My server computer has Ubuntu 12.04 LTS with one static
ip address.

freeswitch version output: FreeSWITCH Version
1.3.13b+git~20130205T003128Z~70a9560306 (git 70a9560 2013-02-05 00:31:28Z)

We were using the system with 4 digits number sip account names without any
problem. Also the account name will be used as dial number. An example of
the user xml file is below. I changed the regex in dialpan/default.xml. The
changings were perfectly succesfull with, again, 4 digits number. But when
trying to include any other number of digits (3, 5 and 6 were tested), it
doesn't work(When I change the regex to accept only 5 digits numbers, 4
digits ones didnt work as expected). I really could not understand why it is
happening. Why there was no problem with 4 digits number and why the exact
same system does not work with this basic change.

To explain the errors more, I want to talk about my tests. Firstly I used 4
digits number user. This test repeated with tls and srtp. These two test
were succesfull. 

And the secand test is same with first test but with 5 digits numbers
without tls and srtp. Registration was succesfull but cant call. (or the
call could not be forwarded) Of course I changed the regex and execute
reloadxml in this test. GSM (8kHz) and G722(16kHz) codecs were used. As you
see below, CODEC NEGOTIATION ERROR occured. After getting this error I
changed the codes as SILK(16kHz). With this change I made the third test.
Third test result is also below. 

show registretions output: 

reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostn
ame,metadata

60022,my.server.ip.address,oOnxiVJFAgQWLABrD01UsYTVOY3TVSlx,sofia/internal/s
ip:60022 at 141.196.174.60:52245;ob,1368271435,141.196.174.60,52245,udp,server,

60021,my.server.ip.address,5r4MTDiZPhs5qzdin9A3hEUh1zZsdqqk,sofia/internal/s
ip:60021 at 141.196.174.60:57938;ob,1368271446,141.196.174.60,57938,udp,server,

@Sean, sorry but I cant post my whole log file because my server has got a
network attack so I am quite busy with this attacker. And also I dont think
CSipSimple has a problem with 5 digits because this system (with 5 digits)
was succesfull with Kamailio and CSipSimple.

If I could not be clear please let me know. Thanks...

user xml example: This was exact same with the default users in freeswitch.
Only the number changed.

<include>

  <user id="60022">

    <params>

      <param name="password" value="$${default_password}"/>

      <param name="vm-password" value="60022"/>

    </params>

    <variables>

      <variable name="toll_allow" value="domestic,international,local"/>

      <variable name="accountcode" value="60022"/>

      <variable name="user_context" value="default"/>

      <variable name="effective_caller_id_name" value="Extension 60022"/>

      <variable name="effective_caller_id_number" value="60022"/>

      <variable name="outbound_caller_id_name"
value="$${outbound_caller_name}"/>

      <variable name="outbound_caller_id_number"
value="$${outbound_caller_id}"/>

      <variable name="callgroup" value="techsupport"/>

    </variables>

  </user>

</include>

The second test error:

2013-05-11 12:13:56.800443 [DEBUG] sofia_reg.c:1511 Send challenge for
[60021 at my.server.ip.address]

2013-05-11 12:13:56.900444 [DEBUG] sofia_reg.c:1511 Send challenge for
[60021 at my.server.ip.address]

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60021'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60021'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60021'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:13:56.920444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60021'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60021'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60021'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:13:56.980451 [DEBUG] sofia_reg.c:1683 Register:

From:    [60021 at my.server.ip.address]

Contact: ["user" <sip:60021 at 141.196.174.60:54008;ob>]

Expires: [900]

2013-05-11 12:14:06.820443 [DEBUG] sofia_reg.c:1511 Send challenge for
[60022 at my.server.ip.address]

2013-05-11 12:14:06.900444 [DEBUG] sofia_reg.c:1511 Send challenge for
[60022 at my.server.ip.address]

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60022'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60022'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60022'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:14:06.980444 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60022'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60022'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60022'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:14:07.020442 [DEBUG] sofia_reg.c:1683 Register:

From:    [60022 at my.server.ip.address]

Contact: ["user" <sip:60022 at 141.196.174.60:33822;ob>]

Expires: [900]

2013-05-11 12:14:14.640437 [NOTICE] switch_channel.c:968 New Channel
sofia/internal/60021 at my.server.ip.address
[26730cd2-ba1b-11e2-acc5-bda7cbfd9554]

2013-05-11 12:14:14.640437 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.640437 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.640437 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_NEW

2013-05-11 12:14:14.640437 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/60021 at my.server.ip.address) State NEW

2013-05-11 12:14:14.660438 [DEBUG] sofia.c:7733 IP 141.196.174.60 Rejected
by acl "domains". Falling back to Digest auth.

2013-05-11 12:14:14.660438 [DEBUG] sofia_reg.c:1511 Send challenge for
[60022 at my.server.ip.address]

2013-05-11 12:14:14.660438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.660438 [DEBUG] sofia.c:1719 detaching session
26730cd2-ba1b-11e2-acc5-bda7cbfd9554

2013-05-11 12:14:14.780439 [DEBUG] sofia.c:1811 Re-attaching to session
26730cd2-ba1b-11e2-acc5-bda7cbfd9554

2013-05-11 12:14:14.780439 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.780439 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] sofia.c:7733 IP 141.196.174.60 Rejected
by acl "domains". Falling back to Digest auth.

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60021'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60021'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60021'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:14:14.800439 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:14:14.800439 [DEBUG] sofia.c:5578 Channel
sofia/internal/60021 at my.server.ip.address entering state [received][100]

2013-05-11 12:14:14.800439 [DEBUG] sofia.c:5589 Remote SDP:

v=0

o=- 3577252345 3577252345 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4010 RTP/AVP 8 0 3 101

c=IN IP4 141.196.174.60

a=rtpmap:8 PCMA/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:3 GSM/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4011 IN IP4 192.168.43.10

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:fig56WojEoKmN07gnvdJZ9Mk6lznskMJszpBOqik

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:HUiy486/260zwSkQ0Z771fKC+g48P9cYEXNqlEYO

2013-05-11 12:14:14.800439 [DEBUG] sofia.c:5802
(sofia/internal/60021 at my.server.ip.address) State Change CS_NEW -> CS_INIT

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_INIT

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/60021 at my.server.ip.address) State INIT

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:86
sofia/internal/60021 at my.server.ip.address SOFIA INIT

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:126
(sofia/internal/60021 at my.server.ip.address) State Change CS_INIT ->
CS_ROUTING                                                 

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/60021 at my.server.ip.address) State INIT going to sleep

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_ROUTING

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:2003
(sofia/internal/60021 at my.server.ip.address) Callstate Change DOWN -> RINGING

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/60021 at my.server.ip.address) State ROUTING

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:149
sofia/internal/60021 at my.server.ip.address SOFIA ROUTING

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:117
sofia/internal/60021 at my.server.ip.address Standard ROUTING

2013-05-11 12:14:14.800439 [INFO] mod_dialplan_xml.c:557 Processing 60021
<60021>->60022 in context default

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->unloop] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->tod_example] continue=true

Dialplan: sofia/internal/60021 at my.server.ip.address Date/TimeMatch (FAIL)
[tod_example] break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->holiday_example] continue=true

Dialplan: sofia/internal/60021 at my.server.ip.address Date/TimeMatch (FAIL)
[holiday_example] break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->global-intercept] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[global-intercept] destination_number(60022) =~ /^886$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->group-intercept] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[group-intercept] destination_number(60022) =~ /^\*8$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->intercept-ext] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[intercept-ext] destination_number(60022) =~ /^\*\*(\d+)$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->redial] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [redial]
destination_number(60022) =~ /^(redial|870)$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->global] continue=true

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [global]
${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
break=never                

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (PASS) [global]
${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/
break=on-false                 

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (PASS) [global]
${switch_r_sdp}(v=0

o=- 3577252345 3577252345 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4010 RTP/AVP 8 0 3 101

c=IN IP4 141.196.174.60

a=rtpmap:8 PCMA/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:3 GSM/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4011 IN IP4 192.168.43.10

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:fig56WojEoKmN07gnvdJZ9Mk6lznskMJszpBOqik

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:HUiy486/260zwSkQ0Z771fKC+g48P9cYEXNqlEYO

) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(sip_secure_media=true)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
export(sip_secure_media=true)

Dialplan: sofia/internal/60021 at my.server.ip.address Absolute Condition
[global]

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_numbe
r})                                        

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/global/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->snom-demo-2] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[snom-demo-2] destination_number(60022) =~ /^9001$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->snom-demo-1] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[snom-demo-1] destination_number(60022) =~ /^9000$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->eavesdrop] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [eavesdrop]
destination_number(60022) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->eavesdrop] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [eavesdrop]
destination_number(60022) =~ /^779$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->call_return] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[call_return] destination_number(60022) =~ /^\*69$|^869$|^lcr$/
break=on-false                                   

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->del-group] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [del-group]
destination_number(60022) =~ /^80(\d{2})$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->add-group] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL) [add-group]
destination_number(60022) =~ /^81(\d{2})$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->call-group-simo] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[call-group-simo] destination_number(60022) =~ /^82(\d{2})$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->call-group-order] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[call-group-order] destination_number(60022) =~ /^83(\d{2})$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->extension-intercom] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (FAIL)
[extension-intercom] destination_number(60022) =~ /^8(10[01][0-9])$/
break=on-false                              

Dialplan: sofia/internal/60021 at my.server.ip.address parsing
[default->Local_Extension] continue=false

Dialplan: sofia/internal/60021 at my.server.ip.address Regex (PASS)
[Local_Extension] destination_number(60022) =~
/^([0-9][0-9][0-9][0-9]|[0-9][0-9][0-9][0-9][0-9])$/ break=on-false

Dialplan: sofia/internal/60021 at my.server.ip.address Action
export(dialed_extension=60022)

Dialplan: sofia/internal/60021 at my.server.ip.address Action bind_meta_app(1 b
s execute_extension::dx XML features)

Dialplan: sofia/internal/60021 at my.server.ip.address Action bind_meta_app(2 b
s
record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strft
ime(%Y-%m-%d-%H-%M-%S)}.wav)

Dialplan: sofia/internal/60021 at my.server.ip.address Action bind_meta_app(3 b
s execute_extension::cf XML features)

Dialplan: sofia/internal/60021 at my.server.ip.address Action bind_meta_app(4 b
s execute_extension::att_xfer XML features)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(ringback=${us-ring})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(transfer_ringback=local_stream://moh)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(call_timeout=30)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(hangup_after_bridge=true)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(continue_on_fail=true)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe
r})                                        

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})                             

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})

Dialplan: sofia/internal/60021 at my.server.ip.address Action
bridge(user/${dialed_extension}@${domain_name})

Dialplan: sofia/internal/60021 at my.server.ip.address Action answer()

Dialplan: sofia/internal/60021 at my.server.ip.address Action sleep(1000)

Dialplan: sofia/internal/60021 at my.server.ip.address Action
bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/60021 at my.server.ip.address) State Change CS_ROUTING ->
CS_EXECUTE                              

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/60021 at my.server.ip.address) State ROUTING going to sleep

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_EXECUTE

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:477
(sofia/internal/60021 at my.server.ip.address) State EXECUTE

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:242
sofia/internal/60021 at my.server.ip.address SOFIA EXECUTE

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:209
sofia/internal/60021 at my.server.ip.address Standard EXECUTE

EXECUTE sofia/internal/60021 at my.server.ip.address set(sip_secure_media=true)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET [sip_secure_media]=[true]

EXECUTE sofia/internal/60021 at my.server.ip.address
export(sip_secure_media=true)

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [sip_secure_media]=[true]

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-spymap/60021/26730cd2-ba1b-11e2-acc5-bda7cb
fd9554)                                                   

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/60021/60022)

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/global/26730cd2-ba1b-11e2-acc5-bd
a7cbfd9554)                                               

EXECUTE sofia/internal/60021 at my.server.ip.address export(RFC2822_DATE=Sat,
11 May 2013 12:14:14 +0300)

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [RFC2822_DATE]=[Sat, 11 May 2013 12:14:14 +0300]

EXECUTE sofia/internal/60021 at my.server.ip.address
export(dialed_extension=60022)

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [dialed_extension]=[60022]

EXECUTE sofia/internal/60021 at my.server.ip.address bind_meta_app(1 b s
execute_extension::dx XML features)

2013-05-11 12:14:14.800439 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *1
execute_extension::dx XML features

EXECUTE sofia/internal/60021 at my.server.ip.address bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/60021.2013-05-11-12-14-14.w
av)

2013-05-11 12:14:14.800439 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/60021.2013-05-11-12-14-14.w
av

EXECUTE sofia/internal/60021 at my.server.ip.address bind_meta_app(3 b s
execute_extension::cf XML features)

2013-05-11 12:14:14.800439 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *3
execute_extension::cf XML features

EXECUTE sofia/internal/60021 at my.server.ip.address bind_meta_app(4 b s
execute_extension::att_xfer XML features)

2013-05-11 12:14:14.800439 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *4
execute_extension::att_xfer XML features

EXECUTE sofia/internal/60021 at my.server.ip.address
set(ringback=%(2000,4000,440,480))

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET
[ringback]=[%(2000,4000,440,480)]

EXECUTE sofia/internal/60021 at my.server.ip.address
set(transfer_ringback=local_stream://moh)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET
[transfer_ringback]=[local_stream://moh]

EXECUTE sofia/internal/60021 at my.server.ip.address set(call_timeout=30)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET [call_timeout]=[30]

EXECUTE sofia/internal/60021 at my.server.ip.address
set(hangup_after_bridge=true)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET [hangup_after_bridge]=[true]

EXECUTE sofia/internal/60021 at my.server.ip.address set(continue_on_fail=true)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET [continue_on_fail]=[true]

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-call_return/60022/60021)

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/60022/26730cd2-ba1b-11e2-acc5
-bda7cbfd9554)                                            

EXECUTE sofia/internal/60021 at my.server.ip.address
set(called_party_callgroup=techsupport)

2013-05-11 12:14:14.800439 [DEBUG] mod_dptools.c:1349
sofia/internal/60021 at my.server.ip.address SET
[called_party_callgroup]=[techsupport]

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/techsupport/26730cd2-ba1b-11e
2-acc5-bda7cbfd9554)                                      

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/global/26730cd2-ba1b-11e2-acc
5-bda7cbfd9554)                                           

EXECUTE sofia/internal/60021 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/techsupport/26730cd2-ba1b-11e2-ac
c5-bda7cbfd9554)                                          

EXECUTE sofia/internal/60021 at my.server.ip.address
bridge(user/60022 at my.server.ip.address)

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[sip_secure_media]=[true] to event                      

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[RFC2822_DATE]=[Sat, 11 May 2013 12:14:14 +0300] to event

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[dialed_extension]=[60022] to event                     

2013-05-11 12:14:14.800439 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[sip_secure_media]=[true] to event                      

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[RFC2822_DATE]=[Sat, 11 May 2013 12:14:14 +0300] to event

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:1089
sofia/internal/60021 at my.server.ip.address EXPORTING[export_vars]
[dialed_extension]=[60022] to event                     

2013-05-11 12:14:14.800439 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables

2013-05-11 12:14:14.800439 [DEBUG] switch_event.c:1608 Parsing variable
[sip_invite_domain]=[my.server.ip.address]

2013-05-11 12:14:14.800439 [DEBUG] switch_event.c:1608 Parsing variable
[presence_id]=[60022 at my.server.ip.address]

2013-05-11 12:14:14.800439 [NOTICE] switch_channel.c:968 New Channel
sofia/internal/sip:60022 at 141.196.174.60:33822
[268c95ee-ba1b-11e2-ace5-bda7cbfd9554]

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:4961
(sofia/internal/sip:60022 at 141.196.174.60:33822) State Change CS_NEW ->
CS_INIT

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:5031 [zrtp_passthru] Setting
a-leg inherit_codec=true

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:5034 [zrtp_passthru] Setting
b-leg
absolute_codec_string='PCMA at 8000h@20i at 64000b,PCMU at 8000h@20i at 64000b,GSM at 8000h
@20i at 13200b'  

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change CS_INIT

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/sip:60022 at 141.196.174.60:33822) State INIT

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:86
sofia/internal/sip:60022 at 141.196.174.60:33822 SOFIA INIT

2013-05-11 12:14:14.800439 [DEBUG] sofia_glue.c:3157 Set Local Key [1
AES_CM_128_HMAC_SHA1_32 inline:jy7Mnu44PUrnS4nFSUGkaIsFNftmZRTnE61m4sui]

2013-05-11 12:14:14.800439 [DEBUG] sofia_glue.c:2649 Local SDP:

v=0

o=FreeSWITCH 1368242802 1368242803 IN IP4 my.server.ip.address

s=FreeSWITCH

c=IN IP4 my.server.ip.address

t=0 0

m=audio 20852 RTP/SAVP 8 0 3 101 13

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:jy7Mnu44PUrnS4nFSUGkaIsFNftmZRTnE61m4sui

a=ptime:20

a=sendrecv

m=audio 20852 RTP/AVP 8 0 3 101 13

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:126
(sofia/internal/sip:60022 at 141.196.174.60:33822) State Change CS_INIT ->
CS_ROUTING                                       

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/sip:60022 at 141.196.174.60:33822) State INIT going to sleep

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change
CS_ROUTING                          

2013-05-11 12:14:14.800439 [DEBUG] switch_channel.c:2003
(sofia/internal/sip:60022 at 141.196.174.60:33822) Callstate Change DOWN ->
RINGING                                   

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/sip:60022 at 141.196.174.60:33822) State ROUTING

2013-05-11 12:14:14.800439 [DEBUG] mod_sofia.c:149
sofia/internal/sip:60022 at 141.196.174.60:33822 SOFIA ROUTING

2013-05-11 12:14:14.800439 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:60022 at 141.196.174.60:33822) State Change CS_ROUTING ->
CS_CONSUME_MEDIA                    

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/sip:60022 at 141.196.174.60:33822) State ROUTING going to sleep

2013-05-11 12:14:14.800439 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change
CS_CONSUME_MEDIA                    

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:489
(sofia/internal/sip:60022 at 141.196.174.60:33822) State CONSUME_MEDIA

2013-05-11 12:14:14.800439 [DEBUG] switch_core_state_machine.c:489
(sofia/internal/sip:60022 at 141.196.174.60:33822) State CONSUME_MEDIA going to
sleep                       

2013-05-11 12:14:14.800439 [DEBUG] sofia.c:5578 Channel
sofia/internal/sip:60022 at 141.196.174.60:33822 entering state [calling][0]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] sofia.c:5578 Channel
sofia/internal/sip:60022 at 141.196.174.60:33822 entering state
[proceeding][180]                                      

2013-05-11 12:14:14.980444 [NOTICE] sofia.c:5670 Ring-Ready
sofia/internal/sip:60022 at 141.196.174.60:33822!

2013-05-11 12:14:14.980444 [INFO] switch_ivr_originate.c:1185 Sending early
media

2013-05-11 12:14:14.980444 [ERR] sofia_glue.c:4927 a=crypto in RTP/AVP,
refer to rfc3711

2013-05-11 12:14:14.980444 [ERR] mod_sofia.c:2789 CODEC NEGOTIATION ERROR.
SDP:

v=0

o=- 3577252345 3577252345 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4010 RTP/AVP 8 0 3 101

c=IN IP4 141.196.174.60

a=rtpmap:8 PCMA/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:3 GSM/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4011 IN IP4 192.168.43.10

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:fig56WojEoKmN07gnvdJZ9Mk6lznskMJszpBOqik

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:HUiy486/260zwSkQ0Z771fKC+g48P9cYEXNqlEYO

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:830 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_channel.c:2994
(sofia/internal/60021 at my.server.ip.address) Callstate Change RINGING ->
HANGUP                                           

2013-05-11 12:14:14.980444 [NOTICE] switch_channel.c:3216 Hangup
sofia/internal/60021 at my.server.ip.address [CS_EXECUTE]
[INCOMPATIBLE_DESTINATION]

2013-05-11 12:14:14.980444 [DEBUG] switch_channel.c:3017 Send signal
sofia/internal/60021 at my.server.ip.address [KILL]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_ivr_originate.c:1186
sofia/internal/60021 at my.server.ip.address Media Establishment Failed.

2013-05-11 12:14:14.980444 [DEBUG] switch_ivr_originate.c:3533 Originate
Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]

2013-05-11 12:14:14.980444 [DEBUG] switch_channel.c:2994
(sofia/internal/sip:60022 at 141.196.174.60:33822) Callstate Change RINGING ->
HANGUP                                 

2013-05-11 12:14:14.980444 [NOTICE] switch_ivr_originate.c:3620 Hangup
sofia/internal/sip:60022 at 141.196.174.60:33822 [CS_CONSUME_MEDIA]
[ORIGINATOR_CANCEL]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change
CS_HANGUP

2013-05-11 12:14:14.980444 [DEBUG] switch_channel.c:3017 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [KILL]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/sip:60022 at 141.196.174.60:33822) State HANGUP

2013-05-11 12:14:14.980444 [DEBUG] mod_sofia.c:503 Channel
sofia/internal/sip:60022 at 141.196.174.60:33822 hanging up, cause:
ORIGINATOR_CANCEL                               

2013-05-11 12:14:14.980444 [NOTICE] switch_ivr_originate.c:2608 Cannot
create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]

2013-05-11 12:14:14.980444 [DEBUG] switch_ivr_originate.c:3533 Originate
Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]

2013-05-11 12:14:14.980444 [INFO] mod_dptools.c:3060 Originate Failed.
Cause: ORIGINATOR_CANCEL

2013-05-11 12:14:14.980444 [DEBUG] mod_sofia.c:562 Sending CANCEL to
sofia/internal/sip:60022 at 141.196.174.60:33822

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:60022 at 141.196.174.60:33822 Standard HANGUP, cause:
ORIGINATOR_CANCEL                   

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/sip:60022 at 141.196.174.60:33822) State HANGUP going to sleep

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:60022 at 141.196.174.60:33822) State Change CS_HANGUP ->
CS_REPORTING                   

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:2689
sofia/internal/60021 at my.server.ip.address skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:477
(sofia/internal/60021 at my.server.ip.address) State EXECUTE going to sleep

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_HANGUP

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change
CS_REPORTING                        

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/sip:60022 at 141.196.174.60:33822) State REPORTING

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:60022 at 141.196.174.60:33822 Standard REPORTING, cause:
ORIGINATOR_CANCEL                

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/sip:60022 at 141.196.174.60:33822) State REPORTING going to
sleep                           

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/60021 at my.server.ip.address) State HANGUP

2013-05-11 12:14:14.980444 [DEBUG] mod_sofia.c:503 Channel
sofia/internal/60021 at my.server.ip.address hanging up, cause:
INCOMPATIBLE_DESTINATION                                  

2013-05-11 12:14:14.980444 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:60022 at 141.196.174.60:33822) State Change CS_REPORTING ->
CS_DESTROY                  

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60022 at 141.196.174.60:33822 [BREAK]

2013-05-11 12:14:14.980444 [DEBUG] switch_core_session.c:1499 Session 23
(sofia/internal/sip:60022 at 141.196.174.60:33822) Locked, Waiting on external
entities               

2013-05-11 12:14:14.980444 [NOTICE] switch_core_session.c:1517 Session 23
(sofia/internal/sip:60022 at 141.196.174.60:33822) Ended

2013-05-11 12:14:14.980444 [NOTICE] switch_core_session.c:1521 Close Channel
sofia/internal/sip:60022 at 141.196.174.60:33822 [CS_DESTROY]

2013-05-11 12:14:15.000444 [DEBUG] mod_sofia.c:633 Responding to INVITE
with: 488

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:556
(sofia/internal/sip:60022 at 141.196.174.60:33822) Callstate Change HANGUP ->
DOWN                          

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:48
sofia/internal/60021 at my.server.ip.address Standard HANGUP, cause:
INCOMPATIBLE_DESTINATION                      

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/60021 at my.server.ip.address) State HANGUP going to sleep

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/60021 at my.server.ip.address) State Change CS_HANGUP ->
CS_REPORTING                             

2013-05-11 12:14:15.000444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60021 at my.server.ip.address) Running State Change
CS_REPORTING

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:559
(sofia/internal/sip:60022 at 141.196.174.60:33822) Running State Change
CS_DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/60021 at my.server.ip.address) State REPORTING

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:60022 at 141.196.174.60:33822) State DESTROY

2013-05-11 12:14:15.000444 [DEBUG] mod_sofia.c:396
sofia/internal/sip:60022 at 141.196.174.60:33822 SOFIA DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:60022 at 141.196.174.60:33822 Standard DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:60022 at 141.196.174.60:33822) State DESTROY going to sleep

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:92
sofia/internal/60021 at my.server.ip.address Standard REPORTING, cause:
INCOMPATIBLE_DESTINATION

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/60021 at my.server.ip.address) State REPORTING going to sleep

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/60021 at my.server.ip.address) State Change CS_REPORTING ->
CS_DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60021 at my.server.ip.address [BREAK]

2013-05-11 12:14:15.000444 [DEBUG] switch_core_session.c:1499 Session 22
(sofia/internal/60021 at my.server.ip.address) Locked, Waiting on external
entities

2013-05-11 12:14:15.000444 [NOTICE] switch_core_session.c:1517 Session 22
(sofia/internal/60021 at my.server.ip.address) Ended

2013-05-11 12:14:15.000444 [NOTICE] switch_core_session.c:1521 Close Channel
sofia/internal/60021 at my.server.ip.address [CS_DESTROY]

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:556
(sofia/internal/60021 at my.server.ip.address) Callstate Change HANGUP -> DOWN

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:559
(sofia/internal/60021 at my.server.ip.address) Running State Change CS_DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/60021 at my.server.ip.address) State DESTROY

2013-05-11 12:14:15.000444 [DEBUG] mod_sofia.c:396
sofia/internal/60021 at my.server.ip.address SOFIA DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:99
sofia/internal/60021 at my.server.ip.address Standard DESTROY

2013-05-11 12:14:15.000444 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/60021 at my.server.ip.address) State DESTROY going to sleep

2013-05-11 12:29:03.100449 [DEBUG] sofia_reg.c:1511 Send challenge for
[60022 at my.server.ip.address]

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60022'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60022'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60022'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 12:29:05.900434 [DEBUG] sofia_reg.c:1683 Register:

From:    [60022 at my.server.ip.address]

Contact: ["user" <sip:60022 at 141.196.174.60:33822;ob>]

Expires: [900]

third test

2013-05-11 14:08:17.980434 [NOTICE] switch_channel.c:968 New Channel
sofia/internal/60022 at my.server.ip.address
[156488c0-ba2b-11e2-ad18-bda7cbfd9554]

2013-05-11 14:08:17.980434 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:17.980434 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:17.980434 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_NEW

2013-05-11 14:08:17.980434 [DEBUG] switch_core_state_machine.c:433
(sofia/internal/60022 at my.server.ip.address) State NEW

2013-05-11 14:08:18.000438 [DEBUG] sofia.c:7733 IP 141.196.174.60 Rejected
by acl "domains". Falling back to Digest auth.

2013-05-11 14:08:18.000438 [DEBUG] sofia_reg.c:1511 Send challenge for
[60021 at my.server.ip.address]

2013-05-11 14:08:18.000438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.000438 [DEBUG] sofia.c:1719 detaching session
156488c0-ba2b-11e2-ad18-bda7cbfd9554

2013-05-11 14:08:18.120438 [DEBUG] sofia.c:1811 Re-attaching to session
156488c0-ba2b-11e2-ad18-bda7cbfd9554

2013-05-11 14:08:18.120438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.120438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] sofia.c:7733 IP 141.196.174.60 Rejected
by acl "domains". Falling back to Digest auth.

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'record_stereo' = 'true'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_gateway' = 'example.com'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'default_areacode' = '918'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'transfer_fallback_extension' = 'operator'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'toll_allow' = 'domestic,international,local'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'accountcode' = '60022'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'user_context' = 'default'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_name' = 'Extension 60022'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'effective_caller_id_number' = '60022'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_name' = 'FreeSWITCH'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'outbound_caller_id_number' = '0000000000'

2013-05-11 14:08:18.140456 [DEBUG] sofia_reg.c:2767 event_add_header ->
'callgroup' = 'techsupport'

2013-05-11 14:08:18.140456 [DEBUG] sofia.c:5578 Channel
sofia/internal/60022 at my.server.ip.address entering state [received][100]

2013-05-11 14:08:18.140456 [DEBUG] sofia.c:5589 Remote SDP:

v=0

o=- 3577259178 3577259178 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4000 RTP/AVP 97 101

c=IN IP4 141.196.174.60

a=rtpmap:97 SILK/16000

a=fmtp:97 useinbandfec=0

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4001 IN IP4 192.168.43.193

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:+8RV0fxAu+3s1Fc8BQxiMa9ras5u/JDmQ9uCVagu

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:CQ25iu0Z418+mKdV+nRcwXqkd5z+gUxuXsqQt40P

2013-05-11 14:08:18.140456 [DEBUG] sofia.c:5802
(sofia/internal/60022 at my.server.ip.address) State Change CS_NEW -> CS_INIT

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_INIT

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/60022 at my.server.ip.address) State INIT

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:86
sofia/internal/60022 at my.server.ip.address SOFIA INIT

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:126
(sofia/internal/60022 at my.server.ip.address) State Change CS_INIT ->
CS_ROUTING                                                 

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/60022 at my.server.ip.address) State INIT going to sleep

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_ROUTING

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:2003
(sofia/internal/60022 at my.server.ip.address) Callstate Change DOWN -> RINGING

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/60022 at my.server.ip.address) State ROUTING

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:149
sofia/internal/60022 at my.server.ip.address SOFIA ROUTING

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:117
sofia/internal/60022 at my.server.ip.address Standard ROUTING

2013-05-11 14:08:18.140456 [INFO] mod_dialplan_xml.c:557 Processing 60022
<60022>->60021 in context default

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->unloop] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->tod_example] continue=true

Dialplan: sofia/internal/60022 at my.server.ip.address Date/TimeMatch (FAIL)
[tod_example] break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->holiday_example] continue=true

Dialplan: sofia/internal/60022 at my.server.ip.address Date/TimeMatch (FAIL)
[holiday_example] break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->global-intercept] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[global-intercept] destination_number(60021) =~ /^886$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->group-intercept] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[group-intercept] destination_number(60021) =~ /^\*8$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->intercept-ext] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[intercept-ext] destination_number(60021) =~ /^\*\*(\d+)$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->redial] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [redial]
destination_number(60021) =~ /^(redial|870)$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->global] continue=true

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [global]
${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
break=never                

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (PASS) [global]
${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/
break=on-false                 

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (PASS) [global]
${switch_r_sdp}(v=0

o=- 3577259178 3577259178 IN IP4 141.196.174.60

s=pjmedia

c=IN IP4 141.196.174.60

t=0 0

m=audio 4000 RTP/AVP 97 101

c=IN IP4 141.196.174.60

a=rtpmap:97 SILK/16000

a=fmtp:97 useinbandfec=0

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=rtcp:4001 IN IP4 192.168.43.193

a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:+8RV0fxAu+3s1Fc8BQxiMa9ras5u/JDmQ9uCVagu

a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:CQ25iu0Z418+mKdV+nRcwXqkd5z+gUxuXsqQt40P

) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(sip_secure_media=true)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
export(sip_secure_media=true)

Dialplan: sofia/internal/60022 at my.server.ip.address Absolute Condition
[global]

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_numbe
r})                                        

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/global/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->snom-demo-2] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[snom-demo-2] destination_number(60021) =~ /^9001$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->snom-demo-1] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[snom-demo-1] destination_number(60021) =~ /^9000$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->eavesdrop] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [eavesdrop]
destination_number(60021) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->eavesdrop] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [eavesdrop]
destination_number(60021) =~ /^779$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->call_return] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[call_return] destination_number(60021) =~ /^\*69$|^869$|^lcr$/
break=on-false                                   

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->del-group] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [del-group]
destination_number(60021) =~ /^80(\d{2})$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->add-group] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL) [add-group]
destination_number(60021) =~ /^81(\d{2})$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->call-group-simo] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[call-group-simo] destination_number(60021) =~ /^82(\d{2})$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->call-group-order] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[call-group-order] destination_number(60021) =~ /^83(\d{2})$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->extension-intercom] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (FAIL)
[extension-intercom] destination_number(60021) =~ /^8(10[01][0-9])$/
break=on-false                              

Dialplan: sofia/internal/60022 at my.server.ip.address parsing
[default->Local_Extension] continue=false

Dialplan: sofia/internal/60022 at my.server.ip.address Regex (PASS)
[Local_Extension] destination_number(60021) =~
/^([0-9][0-9][0-9][0-9]|[0-9][0-9][0-9][0-9][0-9])$/ break=on-false

Dialplan: sofia/internal/60022 at my.server.ip.address Action
export(dialed_extension=60021)

Dialplan: sofia/internal/60022 at my.server.ip.address Action bind_meta_app(1 b
s execute_extension::dx XML features)

Dialplan: sofia/internal/60022 at my.server.ip.address Action bind_meta_app(2 b
s
record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strft
ime(%Y-%m-%d-%H-%M-%S)}.wav)

Dialplan: sofia/internal/60022 at my.server.ip.address Action bind_meta_app(3 b
s execute_extension::cf XML features)

Dialplan: sofia/internal/60022 at my.server.ip.address Action bind_meta_app(4 b
s execute_extension::att_xfer XML features)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(ringback=${us-ring})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(transfer_ringback=local_stream://moh)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(call_timeout=30)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(hangup_after_bridge=true)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(continue_on_fail=true)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe
r})                                        

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})                             

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})

Dialplan: sofia/internal/60022 at my.server.ip.address Action
bridge(user/${dialed_extension}@${domain_name})

Dialplan: sofia/internal/60022 at my.server.ip.address Action answer()

Dialplan: sofia/internal/60022 at my.server.ip.address Action sleep(1000)

Dialplan: sofia/internal/60022 at my.server.ip.address Action
bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/60022 at my.server.ip.address) State Change CS_ROUTING ->
CS_EXECUTE                              

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/60022 at my.server.ip.address) State ROUTING going to sleep

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_EXECUTE

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:477
(sofia/internal/60022 at my.server.ip.address) State EXECUTE

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:242
sofia/internal/60022 at my.server.ip.address SOFIA EXECUTE

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:209
sofia/internal/60022 at my.server.ip.address Standard EXECUTE

EXECUTE sofia/internal/60022 at my.server.ip.address set(sip_secure_media=true)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET [sip_secure_media]=[true]

EXECUTE sofia/internal/60022 at my.server.ip.address
export(sip_secure_media=true)

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [sip_secure_media]=[true]

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-spymap/60022/156488c0-ba2b-11e2-ad18-bda7cb
fd9554)                                                   

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/60022/60021)

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/global/156488c0-ba2b-11e2-ad18-bd
a7cbfd9554)                                               

EXECUTE sofia/internal/60022 at my.server.ip.address export(RFC2822_DATE=Sat,
11 May 2013 14:08:18 +0300)

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [RFC2822_DATE]=[Sat, 11 May 2013 14:08:18 +0300]

EXECUTE sofia/internal/60022 at my.server.ip.address
export(dialed_extension=60021)

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [dialed_extension]=[60021]

EXECUTE sofia/internal/60022 at my.server.ip.address bind_meta_app(1 b s
execute_extension::dx XML features)

2013-05-11 14:08:18.140456 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *1
execute_extension::dx XML features

EXECUTE sofia/internal/60022 at my.server.ip.address bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/60022.2013-05-11-14-08-18.w
av)

2013-05-11 14:08:18.140456 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/60022.2013-05-11-14-08-18.w
av

EXECUTE sofia/internal/60022 at my.server.ip.address bind_meta_app(3 b s
execute_extension::cf XML features)

2013-05-11 14:08:18.140456 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *3
execute_extension::cf XML features

EXECUTE sofia/internal/60022 at my.server.ip.address bind_meta_app(4 b s
execute_extension::att_xfer XML features)

2013-05-11 14:08:18.140456 [INFO] switch_ivr_async.c:3409 Bound B-Leg: *4
execute_extension::att_xfer XML features

EXECUTE sofia/internal/60022 at my.server.ip.address
set(ringback=%(2000,4000,440,480))

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET
[ringback]=[%(2000,4000,440,480)]

EXECUTE sofia/internal/60022 at my.server.ip.address
set(transfer_ringback=local_stream://moh)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET
[transfer_ringback]=[local_stream://moh]

EXECUTE sofia/internal/60022 at my.server.ip.address set(call_timeout=30)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET [call_timeout]=[30]

EXECUTE sofia/internal/60022 at my.server.ip.address
set(hangup_after_bridge=true)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET [hangup_after_bridge]=[true]

EXECUTE sofia/internal/60022 at my.server.ip.address set(continue_on_fail=true)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET [continue_on_fail]=[true]

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-call_return/60021/60022)

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/60021/156488c0-ba2b-11e2-ad18
-bda7cbfd9554)                                            

EXECUTE sofia/internal/60022 at my.server.ip.address
set(called_party_callgroup=techsupport)

2013-05-11 14:08:18.140456 [DEBUG] mod_dptools.c:1349
sofia/internal/60022 at my.server.ip.address SET
[called_party_callgroup]=[techsupport]

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/techsupport/156488c0-ba2b-11e
2-ad18-bda7cbfd9554)                                      

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial_ext/global/156488c0-ba2b-11e2-ad1
8-bda7cbfd9554)                                           

EXECUTE sofia/internal/60022 at my.server.ip.address
hash(insert/my.server.ip.address-last_dial/techsupport/156488c0-ba2b-11e2-ad
18-bda7cbfd9554)                                          

EXECUTE sofia/internal/60022 at my.server.ip.address
bridge(user/60021 at my.server.ip.address)

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[sip_secure_media]=[true] to event                      

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[RFC2822_DATE]=[Sat, 11 May 2013 14:08:18 +0300] to event

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[dialed_extension]=[60021] to event                     

2013-05-11 14:08:18.140456 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[sip_secure_media]=[true] to event                      

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[RFC2822_DATE]=[Sat, 11 May 2013 14:08:18 +0300] to event

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:1089
sofia/internal/60022 at my.server.ip.address EXPORTING[export_vars]
[dialed_extension]=[60021] to event                     

2013-05-11 14:08:18.140456 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables

2013-05-11 14:08:18.140456 [DEBUG] switch_event.c:1608 Parsing variable
[sip_invite_domain]=[my.server.ip.address]

2013-05-11 14:08:18.140456 [DEBUG] switch_event.c:1608 Parsing variable
[presence_id]=[60021 at my.server.ip.address]

2013-05-11 14:08:18.140456 [NOTICE] switch_channel.c:968 New Channel
sofia/internal/sip:60021 at 141.196.174.60:57938
[157eb0a6-ba2b-11e2-ad38-bda7cbfd9554]

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:4961
(sofia/internal/sip:60021 at 141.196.174.60:57938) State Change CS_NEW ->
CS_INIT

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:5031 [zrtp_passthru] Setting
a-leg inherit_codec=true

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change CS_INIT

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/sip:60021 at 141.196.174.60:57938) State INIT

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:86
sofia/internal/sip:60021 at 141.196.174.60:57938 SOFIA INIT

2013-05-11 14:08:18.140456 [DEBUG] sofia_glue.c:3157 Set Local Key [1
AES_CM_128_HMAC_SHA1_32 inline:FGwgO9qNK7dbHa/ZYQcA2fWT17ktjsvjEt5fYXf4]

2013-05-11 14:08:18.140456 [DEBUG] sofia_glue.c:2649 Local SDP:

v=0

o=FreeSWITCH 1368243506 1368243507 IN IP4 my.server.ip.address

s=FreeSWITCH

c=IN IP4 my.server.ip.address

t=0 0

m=audio 26992 RTP/SAVP 9 0 8 3 101 13

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:FGwgO9qNK7dbHa/ZYQcA2fWT17ktjsvjEt5fYXf4

a=ptime:20

a=sendrecv

m=audio 26992 RTP/AVP 9 0 8 3 101 13

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:126
(sofia/internal/sip:60021 at 141.196.174.60:57938) State Change CS_INIT ->
CS_ROUTING                                       

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:454
(sofia/internal/sip:60021 at 141.196.174.60:57938) State INIT going to sleep

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change
CS_ROUTING                          

2013-05-11 14:08:18.140456 [DEBUG] switch_channel.c:2003
(sofia/internal/sip:60021 at 141.196.174.60:57938) Callstate Change DOWN ->
RINGING                                   

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/sip:60021 at 141.196.174.60:57938) State ROUTING

2013-05-11 14:08:18.140456 [DEBUG] mod_sofia.c:149
sofia/internal/sip:60021 at 141.196.174.60:57938 SOFIA ROUTING

2013-05-11 14:08:18.140456 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:60021 at 141.196.174.60:57938) State Change CS_ROUTING ->
CS_CONSUME_MEDIA                    

2013-05-11 14:08:18.140456 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/sip:60021 at 141.196.174.60:57938) State ROUTING going to sleep

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change
CS_CONSUME_MEDIA                    

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:489
(sofia/internal/sip:60021 at 141.196.174.60:57938) State CONSUME_MEDIA

2013-05-11 14:08:18.140456 [DEBUG] switch_core_state_machine.c:489
(sofia/internal/sip:60021 at 141.196.174.60:57938) State CONSUME_MEDIA going to
sleep                       

2013-05-11 14:08:18.140456 [DEBUG] sofia.c:5578 Channel
sofia/internal/sip:60021 at 141.196.174.60:57938 entering state [calling][0]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:975 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] sofia.c:5578 Channel
sofia/internal/sip:60021 at 141.196.174.60:57938 entering state
[terminated][406]                                      

2013-05-11 14:08:18.340438 [DEBUG] switch_channel.c:2994
(sofia/internal/sip:60021 at 141.196.174.60:57938) Callstate Change RINGING ->
HANGUP                                 

2013-05-11 14:08:18.340438 [NOTICE] sofia.c:6385 Hangup
sofia/internal/sip:60021 at 141.196.174.60:57938 [CS_CONSUME_MEDIA]
[SERVICE_NOT_IMPLEMENTED]

2013-05-11 14:08:18.340438 [DEBUG] switch_channel.c:3017 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [KILL]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change
CS_HANGUP                           

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/sip:60021 at 141.196.174.60:57938) State HANGUP

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:503 Channel
sofia/internal/sip:60021 at 141.196.174.60:57938 hanging up, cause:
SERVICE_NOT_IMPLEMENTED                         

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:60021 at 141.196.174.60:57938 Standard HANGUP, cause:
SERVICE_NOT_IMPLEMENTED             

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/sip:60021 at 141.196.174.60:57938) State HANGUP going to sleep

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:60021 at 141.196.174.60:57938) State Change CS_HANGUP ->
CS_REPORTING                   

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change
CS_REPORTING                        

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/sip:60021 at 141.196.174.60:57938) State REPORTING

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:60021 at 141.196.174.60:57938 Standard REPORTING, cause:
SERVICE_NOT_IMPLEMENTED          

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/sip:60021 at 141.196.174.60:57938) State REPORTING going to
sleep                           

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:60021 at 141.196.174.60:57938) State Change CS_REPORTING ->
CS_DESTROY                  

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/sip:60021 at 141.196.174.60:57938 [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1499 Session 27
(sofia/internal/sip:60021 at 141.196.174.60:57938) Locked, Waiting on external
entities               

2013-05-11 14:08:18.340438 [DEBUG] switch_ivr_originate.c:3533 Originate
Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]

2013-05-11 14:08:18.340438 [NOTICE] switch_core_session.c:1517 Session 27
(sofia/internal/sip:60021 at 141.196.174.60:57938) Ended

2013-05-11 14:08:18.340438 [NOTICE] switch_core_session.c:1521 Close Channel
sofia/internal/sip:60021 at 141.196.174.60:57938 [CS_DESTROY]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:556
(sofia/internal/sip:60021 at 141.196.174.60:57938) Callstate Change HANGUP ->
DOWN

2013-05-11 14:08:18.340438 [NOTICE] switch_ivr_originate.c:2608 Cannot
create outgoing channel of type [user] cause: [SERVICE_NOT_IMPLEMENTED]

2013-05-11 14:08:18.340438 [DEBUG] switch_ivr_originate.c:3533 Originate
Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:559
(sofia/internal/sip:60021 at 141.196.174.60:57938) Running State Change
CS_DESTROY                          

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:60021 at 141.196.174.60:57938) State DESTROY

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:396
sofia/internal/sip:60021 at 141.196.174.60:57938 SOFIA DESTROY

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:60021 at 141.196.174.60:57938 Standard DESTROY

2013-05-11 14:08:18.340438 [INFO] mod_dptools.c:3060 Originate Failed.
Cause: SERVICE_NOT_IMPLEMENTED

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:60021 at 141.196.174.60:57938) State DESTROY going to sleep

EXECUTE sofia/internal/60022 at my.server.ip.address answer()

2013-05-11 14:08:18.340438 [ERR] sofia_glue.c:4927 a=crypto in RTP/AVP,
refer to rfc3711

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:830 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_channel.c:2994
(sofia/internal/60022 at my.server.ip.address) Callstate Change RINGING ->
HANGUP

2013-05-11 14:08:18.340438 [NOTICE] switch_channel.c:3484 Hangup
sofia/internal/60022 at my.server.ip.address [CS_EXECUTE]
[INCOMPATIBLE_DESTINATION]

2013-05-11 14:08:18.340438 [DEBUG] switch_channel.c:3017 Send signal
sofia/internal/60022 at my.server.ip.address [KILL]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:2689
sofia/internal/60022 at my.server.ip.address skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:477
(sofia/internal/60022 at my.server.ip.address) State EXECUTE going to sleep

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_HANGUP

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/60022 at my.server.ip.address) State HANGUP

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:497
sofia/internal/60022 at my.server.ip.address Overriding SIP cause 488 with 406
from the other leg

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:503 Channel
sofia/internal/60022 at my.server.ip.address hanging up, cause:
INCOMPATIBLE_DESTINATION

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:633 Responding to INVITE
with: 406

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:48
sofia/internal/60022 at my.server.ip.address Standard HANGUP, cause:
INCOMPATIBLE_DESTINATION

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:667
(sofia/internal/60022 at my.server.ip.address) State HANGUP going to sleep

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/60022 at my.server.ip.address) State Change CS_HANGUP ->
CS_REPORTING

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/60022 at my.server.ip.address) Running State Change
CS_REPORTING

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/60022 at my.server.ip.address) State REPORTING

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:92
sofia/internal/60022 at my.server.ip.address Standard REPORTING, cause:
INCOMPATIBLE_DESTINATION

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:749
(sofia/internal/60022 at my.server.ip.address) State REPORTING going to sleep

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/60022 at my.server.ip.address) State Change CS_REPORTING ->
CS_DESTROY

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1291 Send signal
sofia/internal/60022 at my.server.ip.address [BREAK]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_session.c:1499 Session 26
(sofia/internal/60022 at my.server.ip.address) Locked, Waiting on external
entities

2013-05-11 14:08:18.340438 [NOTICE] switch_core_session.c:1517 Session 26
(sofia/internal/60022 at my.server.ip.address) Ended

2013-05-11 14:08:18.340438 [NOTICE] switch_core_session.c:1521 Close Channel
sofia/internal/60022 at my.server.ip.address [CS_DESTROY]

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:556
(sofia/internal/60022 at my.server.ip.address) Callstate Change HANGUP -> DOWN

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:559
(sofia/internal/60022 at my.server.ip.address) Running State Change CS_DESTROY

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/60022 at my.server.ip.address) State DESTROY

2013-05-11 14:08:18.340438 [DEBUG] mod_sofia.c:396
sofia/internal/60022 at my.server.ip.address SOFIA DESTROY

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:99
sofia/internal/60022 at my.server.ip.address Standard DESTROY

2013-05-11 14:08:18.340438 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/60022 at my.server.ip.address) State DESTROY going to sleep

2013/5/10 Steven Ayre <steveayre at gmail.com>

Are you using the default dialplan?

Chances are your destination_number condition's regex for the extension that
calls users is limited to 4 digits.

Eg

\d\d\d\d

\d{4}

-Steve

On 10 May 2013 12:30, Burak BorYazılım <mburakbor at gmail.com> wrote:

Hello,

I have problems with adding new user to freeswitch. When trying to add user
with user id has different number of digits than 4, it can register but it
cant call or cant be called. I changed local extension regular expression in
dialpan default.xml but the changes only work with four digits users(user
ids or dial number) .So I want dial a number that has five or more digits.
What other configurations I must change.

Thank you...

Burak,

_________________________________________________________________________
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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130511/1380d4df/attachment-0001.html 