[Freeswitch-users] Freeswitch installed, ATA registered but no call are possible...

Thu Dec 1 15:46:26 MSK 2011

When I say it doesn't work, I mean that I can only connect the "answering
machine". It doesn't ring.

Following the fs_cli trace... (from logs):
...
2011-12-01 13:42:18.918274 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by
acl "domains". Falling back to Digest auth.
2011-12-01 13:42:29.258256 [DEBUG] sofia.c:7267 IP 90.36.1.89 Rejected by
acl "domains". Falling back to Digest auth.
2011-12-01 13:42:29.258256 [NOTICE] switch_channel.c:920 New Channel
sofia/internal/1004 at connexur.dyndns.org
[ee2049ee-1c19-11e1-abcd-1f494360f62d]
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_NEW
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:380
(sofia/internal/1004 at connexur.dyndns.org) State NEW
2011-12-01 13:42:29.268425 [DEBUG] sofia.c:8186 Setting NAT mode based on
nat.auto
2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5282 Channel
sofia/internal/1004 at connexur.dyndns.org entering state [received][100]
2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5293 Remote SDP:
v=0
o=- 9 2 IN IP4 192.168.1.10
s=CounterPath X-Lite 3.0
c=IN IP4 192.168.1.10
t=0 0
m=audio 64860 RTP/AVP 107 119 0 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : PBDGzwKZ EILmrBFJ 192.168.1.10 64860

2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[G7221:115:32000:20:48000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[G7221:107:16000:20:32000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[G722:9:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[PCMU:0:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[PCMA:8:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[GSM:3:8000:20:13200]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[PCMA:8:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32:107:16000:20:0]/[GSM:3:8000:20:13200]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[G7221:115:32000:20:48000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[G7221:107:16000:20:32000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[G722:9:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[PCMU:0:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[PCMA:8:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[BV32-FEC:119:16000:20:0]/[GSM:3:8000:20:13200]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4750 Audio Codec Compare
[PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:2864 Set Codec
sofia/internal/1004 at connexur.dyndns.org PCMU/8000 20 ms 160 samples 64000
bits
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:4871 Set 2833 dtmf send/recv
payload to 101
2011-12-01 13:42:29.268425 [DEBUG] sofia.c:5505
(sofia/internal/1004 at connexur.dyndns.org) State Change CS_NEW -> CS_INIT
2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_INIT
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401
(sofia/internal/1004 at connexur.dyndns.org) State INIT
2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:85
sofia/internal/1004 at connexur.dyndns.org SOFIA INIT
2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:125
(sofia/internal/1004 at connexur.dyndns.org) State Change CS_INIT -> CS_ROUTING
2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:401
(sofia/internal/1004 at connexur.dyndns.org) State INIT going to sleep
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_ROUTING
2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1871
(sofia/internal/1004 at connexur.dyndns.org) Callstate Change DOWN -> RINGING
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410
(sofia/internal/1004 at connexur.dyndns.org) State ROUTING
2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:148
sofia/internal/1004 at connexur.dyndns.org SOFIA ROUTING
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:104
sofia/internal/1004 at connexur.dyndns.org Standard ROUTING
2011-12-01 13:42:29.268425 [INFO] mod_dialplan_xml.c:481 Processing 1004
<1004>->1001 in context default
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing [default->unloop]
continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->tod_example] continue=true
Dialplan: sofia/internal/1004 at connexur.dyndns.org Date/Time Match (PASS)
[tod_example] break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action set(open=true)
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/1004 at connexur.dyndns.org Date/TimeMatch (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[global-intercept] destination_number(1001) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing [default->redial]
continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [redial]
destination_number(1001) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing [default->global]
continue=true
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [global]
${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
break=n$
Dialplan: sofia/internal/1004 at connexur.dyndns.org Absolute Condition
[global]
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->snom-demo-2] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [snom-demo-2]
destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [snom-demo-2]
destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->snom-demo-1] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [snom-demo-1]
destination_number(1001) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->eavesdrop] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [eavesdrop]
destination_number(1001) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->call_return] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [call_return]
destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->del-group] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [del-group]
destination_number(1001) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->add-group] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL) [add-group]
destination_number(1001) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (FAIL)
[extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Regex (PASS)
[Local_Extension] destination_number(1001) =~ /^(10[01][0-9]|1100)$/
break=on-false
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(dialed_extension=1001)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
export(dialed_extension=1001)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime$
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(ringback=${us-ring})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(call_timeout=30)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(continue_on_fail=true)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action answer()
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action sleep(1000)
Dialplan: sofia/internal/1004 at connexur.dyndns.org Action
bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:154
(sofia/internal/1004 at connexur.dyndns.org) State Change CS_ROUTING ->
CS_EXECUTE
2011-12-01 13:42:29.268425 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:410
(sofia/internal/1004 at connexur.dyndns.org) State ROUTING going to sleep
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_EXECUTE
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:417
(sofia/internal/1004 at connexur.dyndns.org) State EXECUTE
2011-12-01 13:42:29.268425 [DEBUG] mod_sofia.c:241
sofia/internal/1004 at connexur.dyndns.org SOFIA EXECUTE
2011-12-01 13:42:29.268425 [DEBUG] switch_core_state_machine.c:192
sofia/internal/1004 at connexur.dyndns.org Standard EXECUTE
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(open=true)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [open]=[true]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-spymap/1004/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial/1004/1001)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec
2011 13:42:29 +0100)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial/global/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(RFC2822_DATE=Thu, 01 Dec
2011 13:42:29 +0100)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [RFC2822_DATE]=[Thu, 01 Dec 2011
13:42:29 +0100]
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(dialed_extension=1001)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [dialed_extension]=[1001]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
export(dialed_extension=1001)
2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1087 EXPORT
(export_vars) [dialed_extension]=[1001]
EXECUTE sofia/internal/1004 at connexur.dyndns.org bind_meta_app(1 b s
execute_extension::dx XML features)
2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *1
execute_extension::dx XML features
EXECUTE sofia/internal/1004 at connexur.dyndns.org bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav)
2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/1004.2011-12-01-13-42-29.wav
EXECUTE sofia/internal/1004 at connexur.dyndns.org bind_meta_app(3 b s
execute_extension::cf XML features)
2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *3
execute_extension::cf XML features
EXECUTE sofia/internal/1004 at connexur.dyndns.org bind_meta_app(4 b s
execute_extension::att_xfer XML features)
2011-12-01 13:42:29.268425 [INFO] switch_ivr_async.c:3130 Bound B-Leg: *4
execute_extension::att_xfer XML features
EXECUTE sofia/internal/1004 at connexur.dyndns.org
set(ringback=%(2000,4000,440.0,480.0))
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET
[ringback]=[%(2000,4000,440.0,480.0)]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
set(transfer_ringback=local_stream://moh)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(call_timeout=30)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [call_timeout]=[30]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
set(hangup_after_bridge=true)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1004 at connexur.dyndns.org set(continue_on_fail=true)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET [continue_on_fail]=[true]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-call_return/1001/1004)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial_ext/1001/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial_ext//ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial_ext/global/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
set(called_party_callgroup=techsupport)
2011-12-01 13:42:29.268425 [DEBUG] mod_dptools.c:1204
sofia/internal/1004 at connexur.dyndns.org SET
[called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1004 at connexur.dyndns.org
hash(insert/91.204.116.116-last_dial/techsupport/ee2049ee-1c19-11e1-abcd-1f494360f62d)
EXECUTE sofia/internal/1004 at connexur.dyndns.org
bridge(user/1001 at 91.204.116.116)
2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041
sofia/internal/1004 at connexur.dyndns.org EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing
global variables
2011-12-01 13:42:29.268425 [DEBUG] switch_channel.c:1041
sofia/internal/1004 at connexur.dyndns.org EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:1884 Parsing
global variables
2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable
[sip_invite_domain]=[91.204.116.116]
2011-12-01 13:42:29.268425 [DEBUG] switch_event.c:1521 Parsing variable
[presence_id]=[1001 at 91.204.116.116]
2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot
create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate
Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2011-12-01 13:42:29.268425 [NOTICE] switch_ivr_originate.c:2459 Cannot
create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
2011-12-01 13:42:29.268425 [DEBUG] switch_ivr_originate.c:3367 Originate
Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
2011-12-01 13:42:29.268425 [INFO] mod_dptools.c:2838 Originate Failed. 
Cause: USER_NOT_REGISTERED
EXECUTE sofia/internal/1004 at connexur.dyndns.org answer()
2011-12-01 13:42:29.268425 [DEBUG] sofia_glue.c:3116 AUDIO RTP
[sofia/internal/1004 at connexur.dyndns.org] 91.204.116.116 port 21454 ->
192.168.1.10 port 6486$
2011-12-01 13:42:29.268425 [DEBUG] switch_rtp.c:1642 Starting timer [soft]
160 bytes per 20ms
2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3382 Set 2833 dtmf send
payload to 101
2011-12-01 13:42:29.293791 [DEBUG] sofia_glue.c:3388 Set 2833 dtmf receive
payload to 101
2011-12-01 13:42:29.293791 [DEBUG] mod_sofia.c:746 Local SDP
sofia/internal/1004 at connexur.dyndns.org:
v=0
o=FreeSWITCH 1322721895 1322721896 IN IP4 91.204.116.116
s=FreeSWITCH
c=IN IP4 91.204.116.116
t=0 0
c=IN IP4 91.204.116.116
t=0 0
m=audio 21454 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:872 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.293791 [DEBUG] sofia.c:5282 Channel
sofia/internal/1004 at connexur.dyndns.org entering state [completed][200]
2011-12-01 13:42:29.293791 [DEBUG] switch_core_session.c:726 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.293791 [DEBUG] switch_channel.c:3175
(sofia/internal/1004 at connexur.dyndns.org) Callstate Change RINGING -> ACTIVE
2011-12-01 13:42:29.293791 [NOTICE] mod_dptools.c:1071 Channel
[sofia/internal/1004 at connexur.dyndns.org] has been answered
EXECUTE sofia/internal/1004 at connexur.dyndns.org sleep(1000)
2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.568264 [DEBUG] switch_core_session.c:872 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:29.578421 [DEBUG] sofia.c:5282 Channel
sofia/internal/1004 at connexur.dyndns.org entering state [ready][200]
2011-12-01 13:42:29.658301 [INFO] switch_rtp.c:3170 Auto Changing port from
192.168.1.10:64860 to 90.36.1.89:64860
EXECUTE sofia/internal/1004 at connexur.dyndns.org
bridge(loopback/app=voicemail:default 91.204.116.116 1001)
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1041
sofia/internal/1004 at connexur.dyndns.org EXPORTING[export_vars]
[dialed_extension]=[1001] to event
2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:1884 Parsing
global variables
2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel
loopback/app=voicemail:default 91.204.116.116 1001-a
[eebdaf40-1c19-11e1-abd8-1f494360f$
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145
loopback/app=voicemail:default 91.204.116.116 1001-a setup codec
PCMU/8000/20
2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:918 Rename Channel
loopback/app=voicemail:default 91.204.116.116 1001-a->loopback/voicemail-a
[eebdaf40$
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:973 (loopback/voicemail-a)
State Change CS_NEW -> CS_INIT
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_INIT
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401
(loopback/voicemail-a) State INIT
2011-12-01 13:42:30.298263 [NOTICE] switch_channel.c:920 New Channel
loopback/voicemail-b [eebdc6ba-1c19-11e1-abdc-1f494360f62d]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:145 loopback/voicemail-b
setup codec PCMU/8000/20
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:258 (loopback/voicemail-b)
State Change CS_NEW -> CS_INIT
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-b) Running State Change CS_INIT
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401
(loopback/voicemail-b) State INIT
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-b)
State Change CS_INIT -> CS_ROUTING
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401
(loopback/voicemail-b) State INIT going to sleep
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-b) Running State Change CS_ROUTING
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871
(loopback/voicemail-b) Callstate Change DOWN -> RINGING
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410
(loopback/voicemail-b) State ROUTING
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-b
CHANNEL ROUTING
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:355 (loopback/voicemail-b)
State Change CS_ROUTING -> CS_EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410
(loopback/voicemail-b) State ROUTING going to sleep
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-b) Running State Change CS_EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:417
(loopback/voicemail-b) State EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b
CHANNEL EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192
loopback/voicemail-b Standard EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:375 loopback/voicemail-b
CHANNEL EXECUTE
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:192
loopback/voicemail-b Standard EXECUTE
EXECUTE loopback/voicemail-b pre_answer()
2011-12-01 13:42:30.298263 [NOTICE] mod_loopback.c:760 Pre-Answer
loopback/voicemail-a!
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917
(loopback/voicemail-a) Callstate Change DOWN -> EARLY
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:726 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:30.298263 [NOTICE] mod_dptools.c:1097 Pre-Answer
loopback/voicemail-b!
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2917
(loopback/voicemail-b) Callstate Change RINGING -> EARLY
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:2959 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
EXECUTE loopback/voicemail-b voicemail(default 91.204.116.116 1001)
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:304 (loopback/voicemail-a)
State Change CS_INIT -> CS_ROUTING
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:401
(loopback/voicemail-a) State INIT going to sleep
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_ROUTING
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1871
(loopback/voicemail-a) Callstate Change EARLY -> RINGING
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410
(loopback/voicemail-a) State ROUTING
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:336 loopback/voicemail-a
CHANNEL ROUTING
2011-12-01 13:42:30.298263 [DEBUG] switch_ivr_originate.c:66
(loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2011-12-01 13:42:30.298263 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:410
(loopback/voicemail-a) State ROUTING going to sleep
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA
2011-12-01 13:42:30.298263 [DEBUG] switch_channel.c:1875
(loopback/voicemail-a) Callstate Change RINGING -> EARLY
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429
(loopback/voicemail-a) State CONSUME_MEDIA
2011-12-01 13:42:30.298263 [DEBUG] mod_loopback.c:535 CHANNEL CONSUME_MEDIA
2011-12-01 13:42:30.298263 [DEBUG] switch_core_state_machine.c:429
(loopback/voicemail-a) State CONSUME_MEDIA going to sleep
2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_originate.c:3269 Originate
Resulted in Success: [loopback/voicemail-a]
2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:726 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:30.308562 [DEBUG] switch_ivr_bridge.c:1270
(loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2011-12-01 13:42:30.308562 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA
2011-12-01 13:42:30.308562 [DEBUG] switch_core_state_machine.c:420
(loopback/voicemail-a) State EXCHANGE_MEDIA
2011-12-01 13:42:30.308562 [DEBUG] mod_loopback.c:497 CHANNEL LOOPBACK
2011-12-01 13:42:30.398283 [DEBUG] switch_ivr_play_say.c:67 No language
specified - Using [en]
2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:244 Handle
play-file:[voicemail/vm-person.wav] (en:en)
2011-12-01 13:42:30.409312 [DEBUG] switch_ivr_play_say.c:1302 Codec
Activated L16 at 8000hz 1 channels 20ms
2011-12-01 13:42:31.798263 [DEBUG] switch_ivr_play_say.c:1672 done playing
file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:244 Handle
say:[1001] (en:en)
2011-12-01 13:42:31.898264 [DEBUG] switch_ivr_play_say.c:1302 Codec
Activated L16 at 8000hz 1 channels 20ms
2011-12-01 13:42:33.398281 [DEBUG] switch_core_session.c:872 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2833
(sofia/internal/1004 at connexur.dyndns.org) Callstate Change ACTIVE -> HANGUP
2011-12-01 13:42:33.418917 [NOTICE] sofia.c:572 Hangup
sofia/internal/1004 at connexur.dyndns.org [CS_EXECUTE] [NORMAL_CLEARING]
2011-12-01 13:42:33.418917 [DEBUG] switch_channel.c:2856 Send signal
sofia/internal/1004 at connexur.dyndns.org [KILL]
2011-12-01 13:42:33.418917 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD
DONE [sofia/internal/1004 at connexur.dyndns.org]
2011-12-01 13:42:33.418917 [DEBUG] switch_ivr_bridge.c:611 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:33.418917 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD
DONE [loopback/voicemail-a]
2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD
DONE [loopback/voicemail-a]
2011-12-01 13:42:33.438243 [DEBUG] switch_ivr_bridge.c:611 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833
(loopback/voicemail-a) Callstate Change EARLY -> HANGUP
2011-12-01 13:42:33.438243 [NOTICE] switch_ivr_bridge.c:666 Hangup
loopback/voicemail-a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal
loopback/voicemail-a [KILL]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:420
(loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_HANGUP
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602
(loopback/voicemail-a) State HANGUP
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:427 loopback/voicemail-a
CHANNEL HANGUP
2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2833
(loopback/voicemail-b) Callstate Change EARLY -> HANGUP
2011-12-01 13:42:33.438243 [NOTICE] mod_loopback.c:438 Hangup
loopback/voicemail-b [CS_EXECUTE] [NORMAL_CLEARING]
2011-12-01 13:42:33.438243 [DEBUG] switch_channel.c:2856 Send signal
loopback/voicemail-b [KILL]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:47
loopback/voicemail-a Standard HANGUP, cause: NORMAL_CLEARING
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:602
(loopback/voicemail-a) State HANGUP going to sleep
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:393
(loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-a) Running State Change CS_REPORTING
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662
(loopback/voicemail-a) State REPORTING
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:79
loopback/voicemail-a Standard REPORTING, cause: NORMAL_CLEARING
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:662
(loopback/voicemail-a) State REPORTING going to sleep
2011-12-01 13:42:33.438243 [DEBUG] switch_core_state_machine.c:387
(loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-a [BREAK]
2011-12-01 13:42:33.438243 [DEBUG] mod_loopback.c:475 loopback/voicemail-a
CHANNEL KILL
2011-12-01 13:42:33.438243 [DEBUG] switch_core_session.c:1377 Session 145
(loopback/voicemail-a) Locked, Waiting on external entities
2011-12-01 13:42:33.450220 [DEBUG] switch_ivr_bridge.c:1348
sofia/internal/1004 at connexur.dyndns.org skip receive message [UNBRIDGE]
(channel is hungup alrea$
2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:2272
sofia/internal/1004 at connexur.dyndns.org skip receive message
[APPLICATION_EXEC_COMPLETE] (chan$
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:417
(sofia/internal/1004 at connexur.dyndns.org) State EXECUTE going to sleep
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_HANGUP
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602
(sofia/internal/1004 at connexur.dyndns.org) State HANGUP
2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:459
sofia/internal/1004 at connexur.dyndns.org Overriding SIP cause 480 with 200
from the other leg
2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:465 Channel
sofia/internal/1004 at connexur.dyndns.org hanging up, cause: NORMAL_CLEARING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:47
sofia/internal/1004 at connexur.dyndns.org Standard HANGUP, cause:
NORMAL_CLEARING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:602
(sofia/internal/1004 at connexur.dyndns.org) State HANGUP going to sleep
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:393
(sofia/internal/1004 at connexur.dyndns.org) State Change CS_HANGUP ->
CS_REPORTING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:362
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_REPORTING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662
(sofia/internal/1004 at connexur.dyndns.org) State REPORTING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:79
sofia/internal/1004 at connexur.dyndns.org Standard REPORTING, cause:
NORMAL_CLEARING
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:662
(sofia/internal/1004 at connexur.dyndns.org) State REPORTING going to sleep
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:387
(sofia/internal/1004 at connexur.dyndns.org) State Change CS_REPORTING ->
CS_DESTROY
2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1177 Send signal
sofia/internal/1004 at connexur.dyndns.org [BREAK]
2011-12-01 13:42:33.450220 [DEBUG] switch_core_session.c:1377 Session 144
(sofia/internal/1004 at connexur.dyndns.org) Locked, Waiting on external
entities
2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1395 Session 144
(sofia/internal/1004 at connexur.dyndns.org) Ended
2011-12-01 13:42:33.450220 [NOTICE] switch_core_session.c:1397 Close Channel
sofia/internal/1004 at connexur.dyndns.org [CS_DESTROY]
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:491
(sofia/internal/1004 at connexur.dyndns.org) Callstate Change HANGUP -> DOWN
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:494
(sofia/internal/1004 at connexur.dyndns.org) Running State Change CS_DESTROY
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504
(sofia/internal/1004 at connexur.dyndns.org) State DESTROY
2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370
sofia/internal/1004 at connexur.dyndns.org SOFIA DESTROY
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504
(sofia/internal/1004 at connexur.dyndns.org) State DESTROY
2011-12-01 13:42:33.450220 [DEBUG] mod_sofia.c:370
sofia/internal/1004 at connexur.dyndns.org SOFIA DESTROY
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:86
sofia/internal/1004 at connexur.dyndns.org Standard DESTROY
2011-12-01 13:42:33.450220 [DEBUG] switch_core_state_machine.c:504
(sofia/internal/1004 at connexur.dyndns.org) State DESTROY going to sleep
2011-12-01 13:42:33.458337 [DEBUG] switch_ivr_play_say.c:1672 done playing
file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav
2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:2272
loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
(channel is hungup alrea$
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:417
(loopback/voicemail-b) State EXECUTE going to sleep
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-b) Running State Change CS_HANGUP
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602
(loopback/voicemail-b) State HANGUP
2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:427 loopback/voicemail-b
CHANNEL HANGUP
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:47
loopback/voicemail-b Standard HANGUP, cause: NORMAL_CLEARING
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:602
(loopback/voicemail-b) State HANGUP going to sleep
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:393
(loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:362
(loopback/voicemail-b) Running State Change CS_REPORTING
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662
(loopback/voicemail-b) State REPORTING
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:79
loopback/voicemail-b Standard REPORTING, cause: NORMAL_CLEARING
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:662
(loopback/voicemail-b) State REPORTING going to sleep
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:387
(loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1177 Send signal
loopback/voicemail-b [BREAK]
2011-12-01 13:42:33.548273 [DEBUG] mod_loopback.c:475 loopback/voicemail-b
CHANNEL KILL
2011-12-01 13:42:33.548273 [DEBUG] switch_core_session.c:1377 Session 146
(loopback/voicemail-b) Locked, Waiting on external entities
2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1395 Session 146
(loopback/voicemail-b) Ended
2011-12-01 13:42:33.548273 [NOTICE] switch_core_session.c:1397 Close Channel
loopback/voicemail-b [CS_DESTROY]
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:491
(loopback/voicemail-b) Callstate Change HANGUP -> DOWN
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:494
(loopback/voicemail-b) Running State Change CS_DESTROY
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504
(loopback/voicemail-b) State DESTROY
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:86
loopback/voicemail-b Standard DESTROY
2011-12-01 13:42:33.548273 [DEBUG] switch_core_state_machine.c:504
(loopback/voicemail-b) State DESTROY going to sleep
2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1395 Session 145
(loopback/voicemail-a) Ended
2011-12-01 13:42:33.559551 [NOTICE] switch_core_session.c:1397 Close Channel
loopback/voicemail-a [CS_DESTROY]
2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:491
(loopback/voicemail-a) Callstate Change HANGUP -> DOWN
2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:494
(loopback/voicemail-a) Running State Change CS_DESTROY
2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504
(loopback/voicemail-a) State DESTROY
2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:86
loopback/voicemail-a Standard DESTROY
2011-12-01 13:42:33.559551 [DEBUG] switch_core_state_machine.c:504
(loopback/voicemail-a) State DESTROY going to sleep

--
View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Freeswitch-installed-ATA-registered-but-no-call-are-possible-tp7049935p7050389.html
Sent from the freeswitch-users mailing list archive at Nabble.com.