<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
<HTML><HEAD>
<META http-equiv=Content-Type content="text/html; charset=iso-8859-1">
<META content="MSHTML 6.00.6000.16705" name=GENERATOR>
<STYLE></STYLE>
</HEAD>
<BODY
style="WORD-WRAP: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space"
bgColor=#ffffff>
<DIV><FONT face=Arial size=2>Here is the debug info after press F8:</FONT></DIV>
<DIV><FONT face=Arial size=2></FONT> </DIV>
<DIV><FONT face=Arial size=2>2008-10-10 13:33:00 [DEBUG] sofia.c:3134
sofia_handle_sip_i_invite() IP 10.1.1.129 Rejected by acl domains. Falling back
to Digest auth.<BR>2008-10-10 13:33:00 [DEBUG] sofia.c:3134
sofia_handle_sip_i_invite() IP 10.1.1.129 Rejected by acl domains. Falling back
to Digest auth.<BR>2008-10-10 13:33:00 [NOTICE] switch_channel.c:534
switch_channel_set_name() New Channel <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
[41067ebd-0e4a-46e2-942c-f2a953819333]<BR>2008-10-10 13:33:00 [DEBUG]
sofia.c:3624 sofia_handle_sip_i_invite() Setting NAT mode based on via
port<BR>2008-10-10 13:33:00 [DEBUG] sofia.c:2129 sofia_handle_sip_i_state()
Channel <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
entering state [received]<BR>2008-10-10 13:33:00 [DEBUG] sofia.c:2133
sofia_handle_sip_i_state() Remote SDP:<BR>v=0<BR>o=Cisco-SIPUA 11819 0 IN IP4
10.1.1.129<BR>s=SIP Call<BR>t=0 0<BR>m=audio 23142 RTP/AVP 0 8 18 101<BR>c=IN
IP4 10.1.1.129<BR>a=rtpmap:0 PCMU/8000<BR>a=rtpmap:8 PCMA/8000<BR>a=rtpmap:18
G729/8000<BR>a=fmtp:18 annexb=no<BR>a=rtpmap:101
telephone-event/8000<BR>a=fmtp:101 0-15</FONT></DIV>
<DIV> </DIV>
<DIV><FONT face=Arial size=2>2008-10-10 13:33:00 [DEBUG] sofia_glue.c:2280
sofia_glue_negotiate_sdp() Audio Codec Compare
[PCMU:0:8000]/[G722:9:8000]<BR>2008-10-10 13:33:00 [DEBUG] sofia_glue.c:2280
sofia_glue_negotiate_sdp() Audio Codec Compare
[PCMU:0:8000]/[PCMU:0:8000]<BR>2008-10-10 13:33:00 [DEBUG] sofia_glue.c:1530
sofia_glue_tech_set_codec() Set Codec <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
PCMU/8000 20 ms 160 samples<BR>2008-10-10 13:33:00 [DEBUG] sofia_glue.c:2243
sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101<BR>2008-10-10 13:33:00
[DEBUG] sofia.c:2270 sofia_handle_sip_i_state() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
State Change CS_NEW -> CS_INIT<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
[BREAK]<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:365
switch_core_session_run() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Running State Change CS_INIT<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:415 switch_core_session_run() (<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>)
State INIT<BR>2008-10-10 13:33:00 [DEBUG] mod_sofia.c:80 sofia_on_init() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
SOFIA INIT<BR>2008-10-10 13:33:00 [DEBUG] mod_sofia.c:107 sofia_on_init() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
State Change CS_INIT -> CS_ROUTING<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
[BREAK]<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:415
switch_core_session_run() (<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>)
State INIT going to sleep<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:365 switch_core_session_run() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Running State Change CS_ROUTING<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:420 switch_core_session_run() (<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>)
State ROUTING<BR>2008-10-10 13:33:00 [DEBUG] mod_sofia.c:119 sofia_on_routing()
<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
SOFIA ROUTING<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:64
switch_core_standard_on_routing() Standard ROUTING <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A><BR>2008-10-10
13:33:00 [INFO] mod_dialplan_xml.c:222 dialplan_hunt() Processing
Line1->1001@default<BR>2008-10-10 13:33:00 [DEBUG] mod_dialplan_xml.c:107
parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/<BR>2008-10-10
13:33:00 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
${sip_looped_call}() =~ /^true$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
${strftime(%H%M)}(1333) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/<BR>2008-10-10
13:33:00 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^886$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^\*\*(\d+)$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^870$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
${network_addr}(10.1.1.129) =~ /^$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}()
=~ /^$/<BR>2008-10-10 13:33:00 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test
conditions ${call_debug}(false) =~ /^true$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_has_crypto}()
=~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10
13:33:00 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^9001$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^9000$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^88(.*)$|^\*0(.*)$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^779$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^\*69$|^869$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^80(\d{2})$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^81(\d{2})$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^82(\d{2})$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^83(\d{2})$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^8(10[01][0-9])$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:109 parse_exten() Regex mismatch<BR>2008-10-10 13:33:00
[DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions
destination_number(1001) =~ /^(10[01][0-9])$/<BR>2008-10-10 13:33:00 [DEBUG]
mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(1001) =~
/^1007$/<BR>2008-10-10 13:33:00 [DEBUG] mod_dialplan_xml.c:109 parse_exten()
Regex mismatch<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:97
switch_core_standard_on_routing() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
State Change CS_ROUTING -> CS_EXECUTE<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
[BREAK]<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:420
switch_core_session_run() (<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>)
State ROUTING going to sleep<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:365 switch_core_session_run() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Running State Change CS_EXECUTE<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:430 switch_core_session_run() (<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>)
State EXECUTE<BR>2008-10-10 13:33:00 [DEBUG] mod_sofia.c:156 sofia_on_execute()
<A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
SOFIA EXECUTE<BR>2008-10-10 13:33:00 [DEBUG] switch_core_state_machine.c:129
switch_core_standard_on_execute() Standard EXECUTE<BR>2008-10-10 13:33:00
[DEBUG] switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(open=true)<BR>2008-10-10 13:33:00 [DEBUG] mod_dptools.c:678
set_function() SET [open]=[true]<BR>2008-10-10 13:33:00 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat :
default)})<BR>2008-10-10 13:33:00 [DEBUG] switch_core_session.c:1045
switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String set(use_profile=default)<BR>2008-10-10 13:33:00 [DEBUG]
mod_dptools.c:678 set_function() SET [use_profile]=[default]<BR>2008-10-10
13:33:00 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set_user(<A
href="mailto:default@${domain">default@${domain</A>})<BR>2008-10-10 13:33:00
[DEBUG] switch_core_session.c:1045 switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String set_user(<A
href="mailto:default@10.1.1.177">default@10.1.1.177</A>)<BR>2008-10-10 13:33:00
[DEBUG] switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute db(insert/spymap/${caller_id_number}/${uuid})<BR>2008-10-10 13:33:00
[DEBUG] switch_core_session.c:1045 switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String
db(insert/spymap/1007/41067ebd-0e4a-46e2-942c-f2a953819333)<BR>2008-10-10
13:33:00 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute
db(insert/last_dial/${caller_id_number}/${destination_number})<BR>2008-10-10
13:33:00 [DEBUG] switch_core_session.c:1045
switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String db(insert/last_dial/1007/1001)<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute db(insert/last_dial/global/${uuid})<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_session.c:1045 switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String
db(insert/last_dial/global/41067ebd-0e4a-46e2-942c-f2a953819333)<BR>2008-10-10
13:33:01 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(dialed_ext=1001)<BR>2008-10-10 13:33:01 [DEBUG] mod_dptools.c:678
set_function() SET [dialed_ext]=[1001]<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute export(dialed_ext=1001)<BR>2008-10-10 13:33:01 [DEBUG] mod_dptools.c:816
export_function() EXPORT [dialed_ext]=[1001]<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(transfer_ringback=${us-ring})<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_session.c:1045 switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String set(transfer_ringback=%(2000, 4000, 440.0, 480.0))<BR>2008-10-10
13:33:01 [DEBUG] mod_dptools.c:678 set_function() SET
[transfer_ringback]=[%(2000, 4000, 440.0, 480.0)]<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(call_timeout=30)<BR>2008-10-10 13:33:01 [DEBUG] mod_dptools.c:678
set_function() SET [call_timeout]=[30]<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(hangup_after_bridge=true)<BR>2008-10-10 13:33:01 [DEBUG]
mod_dptools.c:678 set_function() SET [hangup_after_bridge]=[true]<BR>2008-10-10
13:33:01 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute set(continue_on_fail=true)<BR>2008-10-10 13:33:01 [DEBUG]
mod_dptools.c:678 set_function() SET [continue_on_fail]=[true]<BR>2008-10-10
13:33:01 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute db(insert/call_return/${dialed_ext}/${caller_id_number})<BR>2008-10-10
13:33:01 [DEBUG] switch_core_session.c:1045
switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String db(insert/call_return/1001/1007)<BR>2008-10-10 13:33:01 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute db(insert/last_dial_ext/${dialed_ext}/${uuid})<BR>2008-10-10 13:33:01
[DEBUG] switch_core_session.c:1045 switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String
db(insert/last_dial_ext/1001/41067ebd-0e4a-46e2-942c-f2a953819333)<BR>2008-10-10
13:33:02 [DEBUG] switch_core_state_machine.c:140
switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute bridge(<A
href="mailto:user/${dialed_ext}@10.1.1.177">user/${dialed_ext}@10.1.1.177</A>)<BR>2008-10-10
13:33:02 [DEBUG] switch_core_session.c:1045
switch_core_session_execute_application() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Expanded String bridge(<A
href="mailto:user/1001@10.1.1.177">user/1001@10.1.1.177</A>)<BR>2008-10-10
13:33:02 [DEBUG] switch_ivr_originate.c:652 switch_ivr_originate() variable
string 0 = [presence_id=1001@10.1.1.177]<BR>2008-10-10 13:33:02 [DEBUG]
switch_ivr_originate.c:652 switch_ivr_originate() variable string 1 =
[transfer_fallback_extension=1001]<BR>2008-10-10 13:33:02 [NOTICE]
switch_channel.c:534 switch_channel_set_name() New Channel <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[1cd3e927-4dd5-413c-98f0-40312774ee02]<BR>2008-10-10 13:33:02 [DEBUG]
mod_sofia.c:2001 sofia_outgoing_channel() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
State Change CS_NEW -> CS_INIT<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[BREAK]<BR>2008-10-10 13:33:02 [DEBUG] switch_core_state_machine.c:365
switch_core_session_run() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
Running State Change CS_INIT<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:415 switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State INIT<BR>2008-10-10 13:33:02 [DEBUG] mod_sofia.c:80 sofia_on_init() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
SOFIA INIT<BR>2008-10-10 13:33:02 [DEBUG] sofia.c:197 sofia_event_callback()
event [nua_i_state] status [0][INVITE sent] session: <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A><BR>2008-10-10
13:33:02 [DEBUG] mod_sofia.c:107 sofia_on_init() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
State Change CS_INIT -> CS_ROUTING<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[BREAK]<BR>2008-10-10 13:33:02 [DEBUG] switch_core_state_machine.c:415
switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State INIT going to sleep<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:365 switch_core_session_run() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
Running State Change CS_ROUTING<BR>2008-10-10 13:33:02 [DEBUG] sofia.c:2129
sofia_handle_sip_i_state() Channel <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
entering state [calling]<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:420 switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State ROUTING<BR>2008-10-10 13:33:02 [DEBUG] mod_sofia.c:119 sofia_on_routing()
<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
SOFIA ROUTING<BR>2008-10-10 13:33:02 [DEBUG] switch_ivr_originate.c:57
originate_on_routing() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
State Change CS_ROUTING -> CS_CONSUME_MEDIA<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_session.c:722 switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[BREAK]<BR>2008-10-10 13:33:02 [DEBUG] switch_core_state_machine.c:420
switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State ROUTING going to sleep<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:365 switch_core_session_run() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
Running State Change CS_CONSUME_MEDIA<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:442 switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State CONSUME_MEDIA<BR>2008-10-10 13:33:02 [DEBUG] sofia.c:197
sofia_event_callback() event [nua_r_invite] status [503][Service Unavailable]
session: <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A><BR>2008-10-10
13:33:02 [DEBUG] sofia.c:197 sofia_event_callback() event [nua_i_state] status
[503][Service Unavailable] session: <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A><BR>2008-10-10
13:33:02 [DEBUG] sofia.c:2129 sofia_handle_sip_i_state() Channel <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
entering state [terminated]<BR>2008-10-10 13:33:02 [NOTICE] sofia.c:2545
sofia_handle_sip_i_state() Hangup <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]<BR>2008-10-10 13:33:02 [DEBUG]
switch_channel.c:1361 switch_channel_perform_hangup() Kill <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[KILL]<BR>2008-10-10 13:33:02 [DEBUG] switch_core_session.c:722
switch_core_session_signal_state_change() Kill <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[BREAK]<BR>2008-10-10 13:33:02 [DEBUG] switch_core_state_machine.c:442
switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State CONSUME_MEDIA going to sleep<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:365 switch_core_session_run() <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
Running State Change CS_HANGUP<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:393 switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State HANGUP<BR>2008-10-10 13:33:02 [DEBUG] mod_sofia.c:264 sofia_on_hangup()
Channel <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
hanging up, cause: NORMAL_TEMPORARY_FAILURE<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP
<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>,
cause: NORMAL_TEMPORARY_FAILURE<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:393 switch_core_session_run() (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
State HANGUP going to sleep<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_session.c:789 switch_core_session_thread() Session 11 (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
Locked, Waiting on external entities<BR>2008-10-10 13:33:02 [DEBUG]
switch_ivr_originate.c:1404 switch_ivr_originate() Originate Resulted in Error
Cause: 41 [NORMAL_TEMPORARY_FAILURE]<BR>2008-10-10 13:33:02 [NOTICE]
switch_core_session.c:807 switch_core_session_thread() Session 11 (<A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>)
Ended<BR>2008-10-10 13:33:02 [NOTICE] switch_core_session.c:809
switch_core_session_thread() Close Channel <A
href="mailto:sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes">sofia/internal/1001@10.1.1.117:51054;transport=udp;fs_nat=yes</A>
[CS_HANGUP]<BR>2008-10-10 13:33:02 [ERR] switch_ivr_originate.c:926
switch_ivr_originate() Cannot create outgoing channel of type [user] cause:
[NORMAL_TEMPORARY_FAILURE]<BR>2008-10-10 13:33:02 [DEBUG]
switch_ivr_originate.c:1404 switch_ivr_originate() Originate Resulted in Error
Cause: 41 [NORMAL_TEMPORARY_FAILURE]<BR>2008-10-10 13:33:02 [INFO]
mod_dptools.c:1789 audio_bridge_function() Originate Failed. Cause:
NORMAL_TEMPORARY_FAILURE<BR>2008-10-10 13:33:02 [DEBUG] mod_dptools.c:1810
audio_bridge_function() Continue on fail [true]: Cause:
NORMAL_TEMPORARY_FAILURE<BR>2008-10-10 13:33:02 [DEBUG]
switch_core_state_machine.c:140 switch_core_standard_on_execute() <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>
Execute answer()<BR>2008-10-10 13:33:02 [DEBUG] sofia_glue.c:1739
sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/1007@10.1.1.177] 10.1.1.177
port 17974 -> 10.1.1.129 port 23142 codec: 0 ms: 20<BR>2008-10-10 13:33:02
[DEBUG] switch_rtp.c:813 switch_rtp_create() Starting timer [soft] 160 bytes per
20000ms<BR>2008-10-10 13:33:02 [DEBUG] mod_sofia.c:430 sofia_answer_channel()
Local SDP <A
href="mailto:sofia/internal/1007@10.1.1.177">sofia/internal/1007@10.1.1.177</A>:<BR>v=0</FONT></DIV>
<DIV><FONT face=Arial size=2></FONT> </DIV>
<DIV><FONT face=Arial size=2>Gary</FONT></DIV></BODY></HTML>