[Freeswitch-users] Newbie- problem with 1 Ext going directly to Voicemail
Charles Bujold
cjbujold at accra.ca
Thu Sep 19 00:08:26 MSD 2013
We have an Extension that if we call we cannot speak to the person it goes
directly to voicemail. We cannot seem to determine why it is doing this.
Any suggestion would be welcomed. I have a copy of the log for the call and
highlighted the sections which may indicate an issue.
Thanks
Cjb
***********************************************************
Dialplan: sofia/internal/100 at 192.168.30.100:5060 parsing
[default->local_extension] continue=false
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Regex (PASS)
[local_extension] destination_number(104) =~ /(^\d{2,7}$)/ break=on-false
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(dialed_extension=104)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
export(dialed_extension=104)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action limit(hash
${domain_name} 104 ${limit_max} ${limit_destination})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${s
trftime(%b)}/${strftime(%d)}/${uuid}.wav)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(ringback=${us-ring})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action set(call_timeout=30)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(continue_on_fail=true)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe
r})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
set(called_party_call_group=${user_data(${dialed_extension}@${domain_name}
var call_group)})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action
bridge(user/${user_data(${destination_number}@${domain_name} attr
id)}@${domain_name})
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action answer()
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action sleep(1000)
Dialplan: sofia/internal/100 at 192.168.30.100:5060 Action voicemail(default
${domain_name} ${dialed_extension})
2013-09-18 16:50:26.133173 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/100 at 192.168.30.100:5060) State Change CS_ROUTING ->
CS_EXECUTE
2013-09-18 16:50:26.133173 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:26.133173 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/100 at 192.168.30.100:5060) State ROUTING going to sleep
2013-09-18 16:50:26.133173 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/100 at 192.168.30.100:5060) Running State Change CS_EXECUTE
2013-09-18 16:50:26.133173 [DEBUG] switch_core_state_machine.c:478
(sofia/internal/100 at 192.168.30.100:5060) State EXECUTE
2013-09-18 16:50:26.133173 [DEBUG] mod_sofia.c:230
sofia/internal/100 at 192.168.30.100:5060 SOFIA EXECUTE
2013-09-18 16:50:26.133173 [DEBUG] switch_core_state_machine.c:209
sofia/internal/100 at 192.168.30.100:5060 Standard EXECUTE
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(call_direction=local)
2013-09-18 16:50:26.133173 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [call_direction]=[local]
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-spymap/100/1481c571-0ba5-4ef0-8649-3ab9f7aecdbf)
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-last_dial/100/104)
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-last_dial/global/1481c571-0ba5-4ef0-8649-3ab9f7ae
cdbf)
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(RFC2822_DATE=Wed, 18 Sep
2013 16:50:26 -0300)
2013-09-18 16:50:26.133173 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [RFC2822_DATE]=[Wed, 18 Sep 2013
16:50:26 -0300]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(dialed_extension=104)
2013-09-18 16:50:26.133173 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [dialed_extension]=[104]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 export(dialed_extension=104)
2013-09-18 16:50:26.133173 [DEBUG] switch_channel.c:1222 EXPORT
(export_vars) [dialed_extension]=[104]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 limit(hash 192.168.30.100 104
5 )
2013-09-18 16:50:26.133173 [INFO] switch_limit.c:126 incr called:
192.168.30.100_104 max:5, interval:0
2013-09-18 16:50:26.133173 [INFO] mod_hash.c:202 Usage for
192.168.30.100_104 is now 1/5
EXECUTE sofia/internal/100 at 192.168.30.100:5060 bind_meta_app(1 b s
execute_extension::dx XML features)
2013-09-18 16:50:26.133173 [INFO] switch_ivr_async.c:3628 Bound B-Leg: *1
execute_extension::dx XML features
EXECUTE sofia/internal/100 at 192.168.30.100:5060 bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/archive/2013/Sep/18/1481c57
1-0ba5-4ef0-8649-3ab9f7aecdbf.wav)
2013-09-18 16:50:26.153076 [INFO] switch_ivr_async.c:3628 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/archive/2013/Sep/18/1481c57
1-0ba5-4ef0-8649-3ab9f7aecdbf.wav
EXECUTE sofia/internal/100 at 192.168.30.100:5060 bind_meta_app(3 b s
execute_extension::cf XML features)
2013-09-18 16:50:26.153076 [INFO] switch_ivr_async.c:3628 Bound B-Leg: *3
execute_extension::cf XML features
EXECUTE sofia/internal/100 at 192.168.30.100:5060 bind_meta_app(4 b s
execute_extension::att_xfer XML features)
2013-09-18 16:50:26.153076 [INFO] switch_ivr_async.c:3628 Bound B-Leg: *4
execute_extension::att_xfer XML features
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(ringback=%(2000, 4000,
440.0, 480.0))
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [ringback]=[%(2000, 4000, 440.0,
480.0)]
EXECUTE sofia/internal/100 at 192.168.30.100:5060
set(transfer_ringback=local_stream://moh)
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(call_timeout=30)
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [call_timeout]=[30]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(hangup_after_bridge=true)
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 set(continue_on_fail=true)
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [continue_on_fail]=[true]
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-call_return/104/100)
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-last_dial_ext/104/1481c571-0ba5-4ef0-8649-3ab9f7a
ecdbf)
EXECUTE sofia/internal/100 at 192.168.30.100:5060
set(called_party_call_group=sales, support, billing)
2013-09-18 16:50:26.153076 [DEBUG] mod_dptools.c:1374
sofia/internal/100 at 192.168.30.100:5060 SET [called_party_call_group]=[sales,
support, billing]
EXECUTE sofia/internal/100 at 192.168.30.100:5060
hash(insert/192.168.30.100-last_dial/sales, support,
billing/1481c571-0ba5-4ef0-8649-3ab9f7aecdbf)
EXECUTE sofia/internal/100 at 192.168.30.100:5060
bridge(user/104 at 192.168.30.100)
2013-09-18 16:50:26.153076 [DEBUG] switch_channel.c:1176
sofia/internal/100 at 192.168.30.100:5060 EXPORTING[export_vars]
[domain_name]=[192.168.30.100] to event
2013-09-18 16:50:26.153076 [DEBUG] switch_channel.c:1176
sofia/internal/100 at 192.168.30.100:5060 EXPORTING[export_vars]
[dialed_extension]=[104] to event
2013-09-18 16:50:26.153076 [DEBUG] switch_ivr_originate.c:2050 Parsing
global variables
2013-09-18 16:50:26.153076 [DEBUG] switch_channel.c:1176
sofia/internal/100 at 192.168.30.100:5060 EXPORTING[export_vars]
[domain_name]=[192.168.30.100] to event
2013-09-18 16:50:26.153076 [DEBUG] switch_channel.c:1176
sofia/internal/100 at 192.168.30.100:5060 EXPORTING[export_vars]
[dialed_extension]=[104] to event
2013-09-18 16:50:26.153076 [DEBUG] switch_ivr_originate.c:2050 Parsing
global variables
2013-09-18 16:50:26.153076 [DEBUG] switch_event.c:1615 Parsing variable
[sip_invite_domain]=[192.168.30.100]
2013-09-18 16:50:26.153076 [DEBUG] switch_event.c:1615 Parsing variable
[presence_id]=[104 at 192.168.30.100]
2013-09-18 16:50:26.153076 [NOTICE] switch_channel.c:1030 New Channel
sofia/internal/sip:104 at 192.168.2.56:5060
[ab4e9db4-127b-4683-9844-6d631f9f8d35]
2013-09-18 16:50:26.153076 [DEBUG] mod_sofia.c:4438
(sofia/internal/sip:104 at 192.168.2.56:5060) State Change CS_NEW -> CS_INIT
2013-09-18 16:50:26.153076 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change CS_INIT
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:104 at 192.168.2.56:5060) State INIT
2013-09-18 16:50:26.153076 [DEBUG] mod_sofia.c:87
sofia/internal/sip:104 at 192.168.2.56:5060 SOFIA INIT
2013-09-18 16:50:26.153076 [DEBUG] sofia_glue.c:1220 Local SDP:
v=0
o=FreeSWITCH 1379503966 1379503967 IN IP4 192.168.30.100
s=FreeSWITCH
c=IN IP4 192.168.30.100
t=0 0
m=audio 29860 RTP/AVP 0 9 8 3 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
2013-09-18 16:50:26.153076 [DEBUG] mod_sofia.c:114
(sofia/internal/sip:104 at 192.168.2.56:5060) State Change CS_INIT ->
CS_ROUTING
2013-09-18 16:50:26.153076 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:104 at 192.168.2.56:5060) State INIT going to sleep
2013-09-18 16:50:26.153076 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change CS_ROUTING
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:104 at 192.168.2.56:5060) State ROUTING
2013-09-18 16:50:26.153076 [DEBUG] mod_sofia.c:137
sofia/internal/sip:104 at 192.168.2.56:5060 SOFIA ROUTING
2013-09-18 16:50:26.153076 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:104 at 192.168.2.56:5060) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2013-09-18 16:50:26.153076 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:104 at 192.168.2.56:5060) State ROUTING going to sleep
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change
CS_CONSUME_MEDIA
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:104 at 192.168.2.56:5060) State CONSUME_MEDIA
2013-09-18 16:50:26.153076 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:104 at 192.168.2.56:5060) State CONSUME_MEDIA going to
sleep
2013-09-18 16:50:26.153076 [DEBUG] sofia.c:5793 Channel
sofia/internal/sip:104 at 192.168.2.56:5060 entering state [calling][0]
2013-09-18 16:50:27.193099 [DEBUG] sofia_reg.c:2224 Changing expire time to
600 by request of proxy sip:sip-slb.voicemeup.com
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] sofia.c:5793 Channel
sofia/internal/sip:104 at 192.168.2.56:5060 entering state [terminated][503]
2013-09-18 16:50:29.153119 [NOTICE] sofia.c:6601 Hangup
sofia/internal/sip:104 at 192.168.2.56:5060 [CS_CONSUME_MEDIA]
[NORMAL_TEMPORARY_FAILURE]
2013-09-18 16:50:29.153119 [DEBUG] switch_channel.c:3135 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [KILL]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change CS_HANGUP
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:104 at 192.168.2.56:5060) State HANGUP
2013-09-18 16:50:29.153119 [DEBUG] mod_sofia.c:463 Channel
sofia/internal/sip:104 at 192.168.2.56:5060 hanging up, cause:
NORMAL_TEMPORARY_FAILURE
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:104 at 192.168.2.56:5060 Standard HANGUP, cause:
NORMAL_TEMPORARY_FAILURE
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/sip:104 at 192.168.2.56:5060) State HANGUP going to sleep
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:692
(sofia/internal/sip:104 at 192.168.2.56:5060) Callstate Change DOWN -> HANGUP
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:447
(sofia/internal/sip:104 at 192.168.2.56:5060) State Change CS_HANGUP ->
CS_REPORTING
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change CS_REPORTING
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/sip:104 at 192.168.2.56:5060) State REPORTING
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:104 at 192.168.2.56:5060 Standard REPORTING, cause:
NORMAL_TEMPORARY_FAILURE
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/sip:104 at 192.168.2.56:5060) State REPORTING going to sleep
2013-09-18 16:50:29.153119 [DEBUG] switch_core_state_machine.c:441
(sofia/internal/sip:104 at 192.168.2.56:5060) State Change CS_REPORTING ->
CS_DESTROY
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/sip:104 at 192.168.2.56:5060 [BREAK]
2013-09-18 16:50:29.153119 [DEBUG] switch_core_session.c:1549 Session 305
(sofia/internal/sip:104 at 192.168.2.56:5060) Locked, Waiting on external
entities
2013-09-18 16:50:29.173113 [DEBUG] switch_ivr_originate.c:3622 Originate
Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2013-09-18 16:50:29.173113 [NOTICE] switch_core_session.c:1567 Session 305
(sofia/internal/sip:104 at 192.168.2.56:5060) Ended
2013-09-18 16:50:29.173113 [NOTICE] switch_core_session.c:1571 Close Channel
sofia/internal/sip:104 at 192.168.2.56:5060 [CS_DESTROY]
2013-09-18 16:50:29.173113 [DEBUG] switch_core_state_machine.c:566
(sofia/internal/sip:104 at 192.168.2.56:5060) Callstate Change HANGUP -> DOWN
2013-09-18 16:50:29.173113 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:104 at 192.168.2.56:5060) Running State Change CS_DESTROY
2013-09-18 16:50:29.173113 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:104 at 192.168.2.56:5060) State DESTROY
2013-09-18 16:50:29.173113 [DEBUG] mod_sofia.c:373
sofia/internal/sip:104 at 192.168.2.56:5060 SOFIA DESTROY
2013-09-18 16:50:29.173113 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:104 at 192.168.2.56:5060 Standard DESTROY
2013-09-18 16:50:29.173113 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:104 at 192.168.2.56:5060) State DESTROY going to sleep
2013-09-18 16:50:29.173113 [NOTICE] switch_ivr_originate.c:2651 Cannot
create outgoing channel of type [user] cause: [NORMAL_TEMPORARY_FAILURE]
2013-09-18 16:50:29.173113 [DEBUG] switch_ivr_originate.c:3622 Originate
Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2013-09-18 16:50:29.173113 [INFO] mod_dptools.c:3173 Originate Failed.
Cause: NORMAL_TEMPORARY_FAILURE
EXECUTE sofia/internal/100 at 192.168.30.100:5060 answer()
2013-09-18 16:50:29.173113 [DEBUG] switch_core_media.c:3986 AUDIO RTP
[sofia/internal/100 at 192.168.30.100:5060] 192.168.30.100 port 25442 ->
192.168.30.50 port 16430 codec: 0 ms: 20
2013-09-18 16:50:29.173113 [DEBUG] switch_rtp.c:2885 Starting timer [soft]
160 bytes per 20ms
2013-09-18 16:50:29.193168 [DEBUG] switch_core_media.c:4320 Set 2833 dtmf
send payload to 101
2013-09-18 16:50:29.193168 [DEBUG] switch_core_media.c:4326 Set 2833 dtmf
receive payload to 101
2013-09-18 16:50:29.193168 [DEBUG] mod_sofia.c:822 Local SDP
sofia/internal/100 at 192.168.30.100:5060:
v=0
o=FreeSWITCH 1379508387 1379508388 IN IP4 192.168.30.100
s=FreeSWITCH
c=IN IP4 192.168.30.100
t=0 0
m=audio 25442 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
2013-09-18 16:50:29.193168 [DEBUG] switch_core_session.c:861 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:29.193168 [NOTICE] mod_dptools.c:1206 Channel
[sofia/internal/100 at 192.168.30.100:5060] has been answered
2013-09-18 16:50:29.193168 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:29.193168 [DEBUG] switch_channel.c:3595
(sofia/internal/100 at 192.168.30.100:5060) Callstate Change RINGING -> ACTIVE
2013-09-18 16:50:29.193168 [DEBUG] sofia.c:5793 Channel
sofia/internal/100 at 192.168.30.100:5060 entering state [completed][200]
EXECUTE sofia/internal/100 at 192.168.30.100:5060 sleep(1000)
2013-09-18 16:50:29.193168 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:29.193168 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:29.193168 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:29.213115 [DEBUG] sofia.c:5793 Channel
sofia/internal/100 at 192.168.30.100:5060 entering state [ready][200]
2013-09-18 16:50:29.233215 [DEBUG] switch_rtp.c:4926 Correct ip/port
confirmed.
EXECUTE sofia/internal/100 at 192.168.30.100:5060 voicemail(default
192.168.30.100 104)
2013-09-18 16:50:30.313134 [DEBUG] switch_ivr_play_say.c:70 No language
specified - Using [en]
2013-09-18 16:50:30.313134 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-person.wav] (en:en)
2013-09-18 16:50:30.313134 [DEBUG] switch_ivr_play_say.c:1315 Codec
Activated L16 at 8000hz 1 channels 20ms
2013-09-18 16:50:31.673132 [DEBUG] switch_ivr_play_say.c:1704 done playing
file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
2013-09-18 16:50:31.773134 [DEBUG] switch_ivr_play_say.c:251 Handle
say:[104] (en:en)
2013-09-18 16:50:31.773134 [DEBUG] switch_ivr_play_say.c:1315 Codec
Activated L16 at 8000hz 1 channels 20ms
2013-09-18 16:50:33.453122 [DEBUG] switch_ivr_play_say.c:1704 done playing
file file_string://digits/1.wav!digits/0.wav!digits/4.wav
2013-09-18 16:50:33.553123 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-not_available.wav] (en:en)
2013-09-18 16:50:33.553123 [DEBUG] switch_ivr_play_say.c:1315 Codec
Activated L16 at 8000hz 1 channels 20ms
2013-09-18 16:50:34.533112 [DEBUG] switch_ivr_play_say.c:1704 done playing
file
/usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
2013-09-18 16:50:34.633211 [DEBUG] switch_ivr_play_say.c:70 No language
specified - Using [en]
2013-09-18 16:50:34.633211 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-record_message.wav] (en:en)
2013-09-18 16:50:34.633211 [DEBUG] switch_ivr_play_say.c:1315 Codec
Activated L16 at 8000hz 1 channels 20ms
2013-09-18 16:50:35.893133 [DEBUG] switch_core_session.c:1006 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:35.913133 [NOTICE] sofia.c:715 Hangup
sofia/internal/100 at 192.168.30.100:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2013-09-18 16:50:35.913133 [DEBUG] switch_channel.c:3135 Send signal
sofia/internal/100 at 192.168.30.100:5060 [KILL]
2013-09-18 16:50:35.913133 [INFO] mod_hash.c:304 Usage for
192.168.30.100_104 is now 0
2013-09-18 16:50:35.913133 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:35.913133 [DEBUG] switch_ivr_play_say.c:1704 done playing
file
/usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav
2013-09-18 16:50:35.913133 [DEBUG] switch_core_session.c:2743
sofia/internal/100 at 192.168.30.100:5060 skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:478
(sofia/internal/100 at 192.168.30.100:5060) State EXECUTE going to sleep
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/100 at 192.168.30.100:5060) Running State Change CS_HANGUP
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/100 at 192.168.30.100:5060) State HANGUP
2013-09-18 16:50:35.913133 [DEBUG] mod_sofia.c:457
sofia/internal/100 at 192.168.30.100:5060 Overriding SIP cause 480 with 503
from the other leg
2013-09-18 16:50:35.913133 [DEBUG] mod_sofia.c:463 Channel
sofia/internal/100 at 192.168.30.100:5060 hanging up, cause: NORMAL_CLEARING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:48
sofia/internal/100 at 192.168.30.100:5060 Standard HANGUP, cause:
NORMAL_CLEARING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:679
(sofia/internal/100 at 192.168.30.100:5060) State HANGUP going to sleep
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:692
(sofia/internal/100 at 192.168.30.100:5060) Callstate Change ACTIVE -> HANGUP
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:447
(sofia/internal/100 at 192.168.30.100:5060) State Change CS_HANGUP ->
CS_REPORTING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/100 at 192.168.30.100:5060) Running State Change CS_REPORTING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/100 at 192.168.30.100:5060) State REPORTING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:92
sofia/internal/100 at 192.168.30.100:5060 Standard REPORTING, cause:
NORMAL_CLEARING
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/100 at 192.168.30.100:5060) State REPORTING going to sleep
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:441
(sofia/internal/100 at 192.168.30.100:5060) State Change CS_REPORTING ->
CS_DESTROY
2013-09-18 16:50:35.913133 [DEBUG] switch_core_session.c:1341 Send signal
sofia/internal/100 at 192.168.30.100:5060 [BREAK]
2013-09-18 16:50:35.913133 [DEBUG] switch_core_session.c:1549 Session 304
(sofia/internal/100 at 192.168.30.100:5060) Locked, Waiting on external
entities
2013-09-18 16:50:35.913133 [NOTICE] switch_core_session.c:1567 Session 304
(sofia/internal/100 at 192.168.30.100:5060) Ended
2013-09-18 16:50:35.913133 [NOTICE] switch_core_session.c:1571 Close Channel
sofia/internal/100 at 192.168.30.100:5060 [CS_DESTROY]
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:566
(sofia/internal/100 at 192.168.30.100:5060) Callstate Change HANGUP -> DOWN
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/100 at 192.168.30.100:5060) Running State Change CS_DESTROY
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/100 at 192.168.30.100:5060) State DESTROY
2013-09-18 16:50:35.913133 [DEBUG] mod_sofia.c:373
sofia/internal/100 at 192.168.30.100:5060 SOFIA DESTROY
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:99
sofia/internal/100 at 192.168.30.100:5060 Standard DESTROY
2013-09-18 16:50:35.913133 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/100 at 192.168.30.100:5060) State DESTROY going to sleep
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130918/4ba89ff3/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users
mailing list