Stuff

public text v1 · immutable
#957025
·published 2008-03-25 18:56 UTC

2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute limit(inbound ${destination_number} ${max_calls})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String limit(inbound 417 1)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[limit_exceeded@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->limit_exceeded@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(limit_exceeded) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval(Limit exceeded!!!!)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${rdnis}@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(417@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${failover_ext}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${rdnis}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(transfer_ringback=${uk-ring})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(transfer_ringback=%(400,200,400,450);%(400,2200,400,450))
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [transfer_ringback]=[%(400,200,400,450);%(400,2200,400,450)]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute transfer(${failover_ext} XML default)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String transfer(417 XML default)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[417@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->417@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(1100) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^886$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*\*(\d+)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^870$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.10.149) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}(US) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [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)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^88(.*)$|^\*0(.*)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*69$|^869$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^80(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^81(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^82(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^83(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^8([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^750$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^315$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(open=true)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [open]=[true]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(use_profile=nat)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [use_profile]=[nat]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/spymap/315/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/315/417)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/global/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${sip_req_user}@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(317@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute info()
2008-03-25 11:00:31 [INFO] mod_dptools.c:663 info_function() CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/default/315@192.168.10.2:5060]
Unique-ID: [91e92f7a-fa84-11dc-bcdc-43ac23e2e574]
Call-Direction: [inbound]
Answer-State: [ringing]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Caller-Username: [315]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Debbie Byrd]
Caller-Caller-ID-Number: [315]
Caller-Network-Addr: [192.168.10.149]
Caller-Destination-Number: [417]
Caller-Unique-ID: [91e92f7a-fa84-11dc-bcdc-43ac23e2e574]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-RDNIS: [limit_exceeded]
Caller-Channel-Name: [sofia/default/315@192.168.10.2:5060]
Caller-Profile-Index: [207]
Caller-Channel-Created-Time: [1206460820480230]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [yes]
Caller-Privacy-Hide-Name: [no]
Caller-Privacy-Hide-Number: [no]
variable_sip_authorized: [true]
variable_sip_mailbox: [315]
variable_sip_auth_username: [315]
variable_sip_auth_realm: [192.168.10.2]
variable_record_stereo: [true]
variable_sip_from_user: [315]
variable_sip_from_port: [5060]
variable_sip_from_uri: [315@192.168.10.2:5060]
variable_sip_from_host: [192.168.10.2]
variable_sip_from_user_stripped: [315]
variable_sip_from_tag: [svfade7yow]
variable_sofia_profile_name: [default]
variable_sofia_profile_domain_name: [192.168.10.2]
variable_sip_req_user: [317]
variable_sip_req_port: [5060]
variable_sip_req_uri: [317@192.168.10.2:5060]
variable_sip_req_host: [192.168.10.2]
variable_sip_to_user: [317]
variable_sip_to_port: [5060]
variable_sip_to_uri: [317@192.168.10.2:5060]
variable_sip_to_host: [192.168.10.2]
variable_sip_contact_params: [line=54zc4bas]
variable_sip_contact_user: [315]
variable_sip_contact_port: [1064]
variable_sip_contact_uri: [315@192.168.10.149:1064]
variable_sip_contact_host: [192.168.10.149]
variable_channel_name: [sofia/default/315@192.168.10.2:5060]
variable_sip_call_id: [3c267a8c1978-pmexlwl9mqrf]
variable_sip_user_agent: [snom370/7.1.30]
variable_sip_via_host: [192.168.10.149]
variable_sip_via_port: [1064]
variable_sip_via_rport: [1064]
variable_max_forwards: [70]
variable_presence_id: [315@192.168.10.2]
variable_sip_h_P-Key-Flags: [resolution="31x13", keys="4"]
variable_switch_r_sdp: [v=0 
o=root 2111373773 2111373773 IN IP4 192.168.10.149 
s=call 
c=IN IP4 192.168.10.149 
t=0 0 
m=audio 64448 RTP/AVP 9 2 101 
a=rtpmap:9 g722/8000 
a=rtpmap:2 g726-32/8000 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=ptime:20 
]
variable_remote_media_ip: [192.168.10.149]
variable_remote_media_port: [64448]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_endpoint_disposition: [RECEIVED]
variable_numbering_plan: [US]
variable_default_gateway: [asterlink.com]
variable_default_area_code: [918]
variable_limit_realm: [inbound]
variable_limit_id: [417]
variable_limit_max: [1]
variable_ringback: [${us-ring}]
variable_transfer_ringback: [%(400,200,400,450);%(400,2200,400,450)]
variable_open: [true]
variable_use_profile: [nat]
variable_mailbox: [317]
variable_accountcode: [317]
variable_user_context: [default]
variable_max_calls: [1]
variable_failover_ext: [417]
variable_user_name: [317]
variable_domain_name: [192.168.10.2]


2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute limit(inbound ${destination_number} ${max_calls})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String limit(inbound 417 1)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[limit_exceeded@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->limit_exceeded@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(limit_exceeded) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval(Limit exceeded!!!!)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${rdnis}@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(417@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${failover_ext}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${rdnis}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(transfer_ringback=${uk-ring})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(transfer_ringback=%(400,200,400,450);%(400,2200,400,450))
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [transfer_ringback]=[%(400,200,400,450);%(400,2200,400,450)]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute transfer(${failover_ext} XML default)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String transfer(417 XML default)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[417@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->417@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(1100) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^886$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*\*(\d+)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^870$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.10.149) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}(US) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [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)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^88(.*)$|^\*0(.*)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*69$|^869$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^80(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^81(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^82(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^83(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^8([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^750$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^315$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(open=true)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [open]=[true]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(use_profile=nat)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [use_profile]=[nat]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/spymap/315/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/315/417)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/global/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${sip_req_user}@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(317@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute info()
2008-03-25 11:00:31 [INFO] mod_dptools.c:663 info_function() CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/default/315@192.168.10.2:5060]
Unique-ID: [91e92f7a-fa84-11dc-bcdc-43ac23e2e574]
Call-Direction: [inbound]
Answer-State: [ringing]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Caller-Username: [315]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Debbie Byrd]
Caller-Caller-ID-Number: [315]
Caller-Network-Addr: [192.168.10.149]
Caller-Destination-Number: [417]
Caller-Unique-ID: [91e92f7a-fa84-11dc-bcdc-43ac23e2e574]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-RDNIS: [limit_exceeded]
Caller-Channel-Name: [sofia/default/315@192.168.10.2:5060]
Caller-Profile-Index: [209]
Caller-Channel-Created-Time: [1206460820480230]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [yes]
Caller-Privacy-Hide-Name: [no]
Caller-Privacy-Hide-Number: [no]
variable_sip_authorized: [true]
variable_sip_mailbox: [315]
variable_sip_auth_username: [315]
variable_sip_auth_realm: [192.168.10.2]
variable_record_stereo: [true]
variable_sip_from_user: [315]
variable_sip_from_port: [5060]
variable_sip_from_uri: [315@192.168.10.2:5060]
variable_sip_from_host: [192.168.10.2]
variable_sip_from_user_stripped: [315]
variable_sip_from_tag: [svfade7yow]
variable_sofia_profile_name: [default]
variable_sofia_profile_domain_name: [192.168.10.2]
variable_sip_req_user: [317]
variable_sip_req_port: [5060]
variable_sip_req_uri: [317@192.168.10.2:5060]
variable_sip_req_host: [192.168.10.2]
variable_sip_to_user: [317]
variable_sip_to_port: [5060]
variable_sip_to_uri: [317@192.168.10.2:5060]
variable_sip_to_host: [192.168.10.2]
variable_sip_contact_params: [line=54zc4bas]
variable_sip_contact_user: [315]
variable_sip_contact_port: [1064]
variable_sip_contact_uri: [315@192.168.10.149:1064]
variable_sip_contact_host: [192.168.10.149]
variable_channel_name: [sofia/default/315@192.168.10.2:5060]
variable_sip_call_id: [3c267a8c1978-pmexlwl9mqrf]
variable_sip_user_agent: [snom370/7.1.30]
variable_sip_via_host: [192.168.10.149]
variable_sip_via_port: [1064]
variable_sip_via_rport: [1064]
variable_max_forwards: [70]
variable_presence_id: [315@192.168.10.2]
variable_sip_h_P-Key-Flags: [resolution="31x13", keys="4"]
variable_switch_r_sdp: [v=0 
o=root 2111373773 2111373773 IN IP4 192.168.10.149 
s=call 
c=IN IP4 192.168.10.149 
t=0 0 
m=audio 64448 RTP/AVP 9 2 101 
a=rtpmap:9 g722/8000 
a=rtpmap:2 g726-32/8000 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=ptime:20 
]
variable_remote_media_ip: [192.168.10.149]
variable_remote_media_port: [64448]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_endpoint_disposition: [RECEIVED]
variable_numbering_plan: [US]
variable_default_gateway: [asterlink.com]
variable_default_area_code: [918]
variable_limit_realm: [inbound]
variable_limit_id: [417]
variable_limit_max: [1]
variable_ringback: [${us-ring}]
variable_transfer_ringback: [%(400,200,400,450);%(400,2200,400,450)]
variable_open: [true]
variable_use_profile: [nat]
variable_mailbox: [317]
variable_accountcode: [317]
variable_user_context: [default]
variable_max_calls: [1]
variable_failover_ext: [417]
variable_user_name: [317]
variable_domain_name: [192.168.10.2]


2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute limit(inbound ${destination_number} ${max_calls})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String limit(inbound 417 1)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[limit_exceeded@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->limit_exceeded@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(limit_exceeded) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval(Limit exceeded!!!!)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${rdnis}@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(417@192.168.10.2)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${failover_ext}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute eval([${rdnis}])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String eval([417])
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(transfer_ringback=${uk-ring})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(transfer_ringback=%(400,200,400,450);%(400,2200,400,450))
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [transfer_ringback]=[%(400,200,400,450);%(400,2200,400,450)]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute transfer(${failover_ext} XML default)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String transfer(417 XML default)
2008-03-25 11:00:31 [DEBUG] switch_ivr.c:995 switch_ivr_session_transfer() sofia/default/315@192.168.10.2:5060 State Change CS_EXECUTE -> CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [NOTICE] switch_ivr.c:1001 switch_ivr_session_transfer() Transfer sofia/default/315@192.168.10.2:5060 to XML[417@default]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->417@default
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(1100) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^886$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*\*(\d+)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^870$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.10.149) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}(US) =~ /^$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [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)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^88(.*)$|^\*0(.*)$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*69$|^869$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^80(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^81(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^82(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^83(\d{2})$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^8([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^750$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^limit_exceeded$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^([34][01][0-9])$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^315$/
2008-03-25 11:00:31 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(open=true)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [open]=[true]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(use_profile=nat)
2008-03-25 11:00:31 [DEBUG] mod_dptools.c:471 set_function() SET [use_profile]=[nat]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/spymap/315/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/315/417)
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/global/91e92f7a-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:31 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [487][Request Terminated] session: sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:31 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/315@192.168.10.2:5060 entering state [terminated]
2008-03-25 11:00:31 [NOTICE] sofia.c:1949 sofia_handle_sip_i_state() Hangup sofia/default/315@192.168.10.2:5060 [CS_EXECUTE] [ORIGINATOR_CANCEL]
2008-03-25 11:00:31 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/315@192.168.10.2:5060 [KILL]
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_HANGUP
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State HANGUP
2008-03-25 11:00:31 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/315@192.168.10.2:5060 hanging up, cause: ORIGINATOR_CANCEL
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/315@192.168.10.2:5060, cause: ORIGINATOR_CANCEL
2008-03-25 11:00:31 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State HANGUP going to sleep
2008-03-25 11:00:31 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 40 (sofia/default/315@192.168.10.2:5060) Locked, Waiting on external entities
2008-03-25 11:00:31 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 40 (sofia/default/315@192.168.10.2:5060) Ended
2008-03-25 11:00:31 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/315@192.168.10.2:5060 [CS_HANGUP]
2008-03-25 11:00:33 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a
2008-03-25 11:00:34 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/315@192.168.10.2:5060 [99fb420c-fa84-11dc-bcdc-43ac23e2e574]
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/315@192.168.10.2:5060 entering state [received]
2008-03-25 11:00:34 [DEBUG] sofia.c:1557 sofia_handle_sip_i_state() Remote SDP:
v=0 
o=root 802967393 802967393 IN IP4 192.168.10.149 
s=call 
c=IN IP4 192.168.10.149 
t=0 0 
m=audio 50136 RTP/AVP 9 2 101 
a=rtpmap:9 g722/8000 
a=rtpmap:2 g726-32/8000 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=ptime:20 

2008-03-25 11:00:34 [DEBUG] sofia_glue.c:2012 sofia_glue_negotiate_sdp() Audio Codec Compare [g722:9:8000]/[G722:9:8000]
2008-03-25 11:00:34 [DEBUG] sofia_glue.c:1335 sofia_glue_tech_set_codec() Set Codec sofia/default/315@192.168.10.2:5060 G722/8000 20 ms 160 samples
2008-03-25 11:00:34 [DEBUG] sofia_glue.c:1976 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-03-25 11:00:34 [DEBUG] sofia.c:1694 sofia_handle_sip_i_state() sofia/default/315@192.168.10.2:5060 State Change CS_NEW -> CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State INIT
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/default/315@192.168.10.2:5060 SOFIA INIT
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/default/315@192.168.10.2:5060 State Change CS_INIT -> CS_RING
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State INIT going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_RING
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/315@192.168.10.2:5060 SOFIA RING
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:34 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing Debbie Byrd->417@default
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(1100) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^886$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*\*(\d+)$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^870$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.10.149) =~ /^$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}() =~ /^$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [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)$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^88(.*)$|^\*0(.*)$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^\*69$|^869$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^80(\d{2})$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^81(\d{2})$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^82(\d{2})$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^83(\d{2})$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^8([34][01][0-9])$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^750$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^limit_exceeded$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^([34][01][0-9])$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(417) =~ /^315$/
2008-03-25 11:00:34 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/315@192.168.10.2:5060 State Change CS_RING -> CS_EXECUTE
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State RING going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_EXECUTE
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/315@192.168.10.2:5060 SOFIA EXECUTE
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(open=true)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [open]=[true]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(use_profile=nat)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [use_profile]=[nat]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(default@${domain})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(default@192.168.10.2)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/spymap/315/99fb420c-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/315/417)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial/global/99fb420c-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set_user(${sip_req_user}@192.168.10.2)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set_user(417@192.168.10.2)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute info()
2008-03-25 11:00:34 [INFO] mod_dptools.c:663 info_function() CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/default/315@192.168.10.2:5060]
Unique-ID: [99fb420c-fa84-11dc-bcdc-43ac23e2e574]
Call-Direction: [inbound]
Answer-State: [ringing]
Channel-Read-Codec-Name: [G722]
Channel-Read-Codec-Rate: [16000]
Channel-Write-Codec-Name: [G722]
Channel-Write-Codec-Rate: [16000]
Caller-Username: [315]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Debbie Byrd]
Caller-Caller-ID-Number: [315]
Caller-Network-Addr: [192.168.10.149]
Caller-Destination-Number: [417]
Caller-Unique-ID: [99fb420c-fa84-11dc-bcdc-43ac23e2e574]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/default/315@192.168.10.2:5060]
Caller-Profile-Index: [1]
Caller-Channel-Created-Time: [1206460834027303]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [yes]
Caller-Privacy-Hide-Name: [no]
Caller-Privacy-Hide-Number: [no]
variable_sip_authorized: [true]
variable_sip_mailbox: [315]
variable_sip_auth_username: [315]
variable_sip_auth_realm: [192.168.10.2]
variable_record_stereo: [true]
variable_failover_ext: [415]
variable_sip_from_user: [315]
variable_sip_from_port: [5060]
variable_sip_from_uri: [315@192.168.10.2:5060]
variable_sip_from_host: [192.168.10.2]
variable_sip_from_user_stripped: [315]
variable_sip_from_tag: [6lyrfscny5]
variable_sofia_profile_name: [default]
variable_sofia_profile_domain_name: [192.168.10.2]
variable_sip_req_user: [417]
variable_sip_req_port: [5060]
variable_sip_req_uri: [417@192.168.10.2:5060]
variable_sip_req_host: [192.168.10.2]
variable_sip_to_user: [417]
variable_sip_to_port: [5060]
variable_sip_to_uri: [417@192.168.10.2:5060]
variable_sip_to_host: [192.168.10.2]
variable_sip_contact_params: [line=54zc4bas]
variable_sip_contact_user: [315]
variable_sip_contact_port: [1064]
variable_sip_contact_uri: [315@192.168.10.149:1064]
variable_sip_contact_host: [192.168.10.149]
variable_channel_name: [sofia/default/315@192.168.10.2:5060]
variable_sip_call_id: [3c267aa0cfe2-my5ap4t3apcd]
variable_sip_user_agent: [snom370/7.1.30]
variable_sip_via_host: [192.168.10.149]
variable_sip_via_port: [1064]
variable_sip_via_rport: [1064]
variable_max_forwards: [70]
variable_presence_id: [315@192.168.10.2]
variable_sip_h_P-Key-Flags: [resolution="31x13", keys="4"]
variable_switch_r_sdp: [v=0 
o=root 802967393 802967393 IN IP4 192.168.10.149 
s=call 
c=IN IP4 192.168.10.149 
t=0 0 
m=audio 50136 RTP/AVP 9 2 101 
a=rtpmap:9 g722/8000 
a=rtpmap:2 g726-32/8000 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-16 
a=ptime:20 
]
variable_remote_media_ip: [192.168.10.149]
variable_remote_media_port: [50136]
variable_read_codec: [G722]
variable_read_rate: [16000]
variable_write_codec: [G722]
variable_write_rate: [16000]
variable_endpoint_disposition: [RECEIVED]
variable_open: [true]
variable_use_profile: [nat]
variable_numbering_plan: [US]
variable_default_gateway: [asterlink.com]
variable_default_area_code: [918]
variable_mailbox: [317]
variable_accountcode: [317]
variable_user_context: [default]
variable_max_calls: [5]
variable_ringback: [${us-ring}]
variable_user_name: [417]
variable_domain_name: [192.168.10.2]


2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute limit(inbound ${destination_number} ${max_calls})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String limit(inbound 417 5)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(dialed_ext=417)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [dialed_ext]=[417]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute export(dialed_ext=417)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:604 export_function() EXPORT [dialed_ext]=[417]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute bind_meta_app(1 a a execute_extension::dx XML features)
2008-03-25 11:00:34 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 1 execute_extension::dx XML features
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute bind_meta_app(2 a a record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String bind_meta_app(2 a a record_session::/usr/local/freeswitch/recordings/315.2008-03-25-11-00-34.wav)
2008-03-25 11:00:34 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 2 record_session::/usr/local/freeswitch/recordings/315.2008-03-25-11-00-34.wav
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute bind_meta_app(3 a a execute_extension::cf XML features)
2008-03-25 11:00:34 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 3 execute_extension::cf XML features
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(transfer_ringback=${us-ring})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(transfer_ringback=%(2000, 4000, 440.0, 480.0))
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [transfer_ringback]=[%(2000, 4000, 440.0, 480.0)]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(call_timeout=30)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [call_timeout]=[30]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(sip_exclude_contact=${network_addr})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String set(sip_exclude_contact=192.168.10.149)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [sip_exclude_contact]=[192.168.10.149]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(hangup_after_bridge=true)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [hangup_after_bridge]=[true]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute set(continue_on_fail=true)
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:471 set_function() SET [continue_on_fail]=[true]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/call_return/${dialed_ext}/${caller_id_number})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/call_return/417/315)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute db(insert/last_dial_ext/${dialed_ext}/${uuid})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String db(insert/last_dial_ext/417/99fb420c-fa84-11dc-bcdc-43ac23e2e574)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute bridge(user/${dialed_ext}@192.168.10.2)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String bridge(user/417@192.168.10.2)
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:609 switch_ivr_originate() variable string 0 = [presence_id=417@192.168.10.2]
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:609 switch_ivr_originate() variable string 1 = [transfer_fallback_extension=417]
2008-03-25 11:00:34 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [9a1a1272-fa84-11dc-bcdc-43ac23e2e574]
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:1824 sofia_outgoing_channel() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k State Change CS_NEW -> CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [BREAK]
2008-03-25 11:00:34 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd [9a1a3356-fa84-11dc-bcdc-43ac23e2e574]
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:1824 sofia_outgoing_channel() sofia/default/417@192.168.10.150:1046;line=u83t1yyd State Change CS_NEW -> CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k Running State Change CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State INIT
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k SOFIA INIT
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/default/417@192.168.10.148:2075;line=a8pw3t1k
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k State Change CS_INIT -> CS_RING
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State INIT going to sleep
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/417@192.168.10.148:2075;line=a8pw3t1k entering state [calling]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k Running State Change CS_RING
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State RING
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k SOFIA RING
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:55 originate_on_ring() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k State Change CS_RING -> CS_HOLD
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State RING going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k Running State Change CS_HOLD
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:479 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State HOLD
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.150:1046;line=u83t1yyd Running State Change CS_INIT
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State INIT
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/default/417@192.168.10.150:1046;line=u83t1yyd SOFIA INIT
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/default/417@192.168.10.150:1046;line=u83t1yyd
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/default/417@192.168.10.150:1046;line=u83t1yyd State Change CS_INIT -> CS_RING
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:452 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State INIT going to sleep
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd entering state [calling]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.150:1046;line=u83t1yyd Running State Change CS_RING
2008-03-25 11:00:34 [INFO] mod_sofia.c:1028 sofia_receive_message() Asked to send early media by sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:34 [DEBUG] sofia_glue.c:1525 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/315@192.168.10.2:5060] 192.168.10.2:25980->192.168.10.149:50136 codec: 9 ms: 20
2008-03-25 11:00:34 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State RING
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/417@192.168.10.150:1046;line=u83t1yyd SOFIA RING
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:55 originate_on_ring() sofia/default/417@192.168.10.150:1046;line=u83t1yyd State Change CS_RING -> CS_HOLD
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State RING going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.150:1046;line=u83t1yyd Running State Change CS_HOLD
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:479 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HOLD
2008-03-25 11:00:34 [INFO] mod_sofia.c:1070 sofia_receive_message() Ring SDP:
v=0
o=FreeSWITCH 1206434854 1206434855 IN IP4 192.168.10.2
s=FreeSWITCH
c=IN IP4 192.168.10.2
t=0 0
a=sendrecv
m=audio 25980 RTP/AVP 9 101 13
a=rtpmap:9 g722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2008-03-25 11:00:34 [NOTICE] switch_channel.c:1380 switch_channel_perform_mark_pre_answered() Ring-Ready sofia/default/315@192.168.10.2:5060!
2008-03-25 11:00:34 [NOTICE] mod_sofia.c:1073 sofia_receive_message() Pre-Answer sofia/default/315@192.168.10.2:5060!
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [183][Session Progress] session: sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/315@192.168.10.2:5060 entering state [early]
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:946 switch_ivr_originate() Raw Codec Activation Success L16@16000hz 1 channel 20ms
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:993 switch_ivr_originate() Play Ringback Tone [${us-ring}]
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_r_invite] status [180][Ringing] session: sofia/default/417@192.168.10.150:1046;line=u83t1yyd
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/default/417@192.168.10.150:1046;line=u83t1yyd
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd entering state [proceeding]
2008-03-25 11:00:34 [NOTICE] sofia.c:1591 sofia_handle_sip_i_state() Ring-Ready sofia/default/417@192.168.10.150:1046;line=u83t1yyd!
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_r_invite] status [180][Ringing] session: sofia/default/417@192.168.10.148:2075;line=a8pw3t1k
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/default/417@192.168.10.148:2075;line=a8pw3t1k
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/417@192.168.10.148:2075;line=a8pw3t1k entering state [proceeding]
2008-03-25 11:00:34 [NOTICE] sofia.c:1591 sofia_handle_sip_i_state() Ring-Ready sofia/default/417@192.168.10.148:2075;line=a8pw3t1k!
2008-03-25 11:00:34 [NOTICE] switch_ivr_originate.c:1149 switch_ivr_originate() Hangup sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [CS_HOLD] [LOSE_RACE]
2008-03-25 11:00:34 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [KILL]
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [BREAK]
2008-03-25 11:00:34 [NOTICE] switch_ivr_originate.c:1149 switch_ivr_originate() Hangup sofia/default/417@192.168.10.150:1046;line=u83t1yyd [CS_HOLD] [LOSE_RACE]
2008-03-25 11:00:34 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [KILL]
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:1235 switch_ivr_originate() Originate Resulted in Error Cause: 502 [LOSE_RACE]
2008-03-25 11:00:34 [ERR] switch_ivr_originate.c:815 switch_ivr_originate() Cannot Create Outgoing Channel! cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] switch_ivr_originate.c:1235 switch_ivr_originate() Originate Resulted in Error Cause: 502 [LOSE_RACE]
2008-03-25 11:00:34 [INFO] mod_dptools.c:1514 audio_bridge_function() Originate Failed.  Cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] mod_dptools.c:1535 audio_bridge_function() Continue on fail [true]:  Cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute answer()
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:376 sofia_answer_channel() Local SDP sofia/default/315@192.168.10.2:5060:
v=0
o=FreeSWITCH 1206434854 1206434856 IN IP4 192.168.10.2
s=FreeSWITCH
c=IN IP4 192.168.10.2
t=0 0
a=sendrecv
m=audio 25980 RTP/AVP 9 101 13
a=rtpmap:9 g722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2008-03-25 11:00:34 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/315@192.168.10.2:5060 entering state [completed]
2008-03-25 11:00:34 [NOTICE] mod_dptools.c:401 answer_function() Channel [sofia/default/315@192.168.10.2:5060] has been answered
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute send_display(Voicemail for ${dialed_ext})
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String send_display(Voicemail for 417)
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute sleep(1000)
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:479 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State HOLD going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.148:2075;line=a8pw3t1k Running State Change CS_HANGUP
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:479 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HOLD going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State HANGUP
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.150:1046;line=u83t1yyd Running State Change CS_HANGUP
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/417@192.168.10.148:2075;line=a8pw3t1k hanging up, cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:291 sofia_on_hangup() Sending CANCEL to sofia/default/417@192.168.10.148:2075;line=a8pw3t1k
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/417@192.168.10.148:2075;line=a8pw3t1k, cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) State HANGUP going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 42 (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) Locked, Waiting on external entities
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HANGUP
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd hanging up, cause: LOSE_RACE
2008-03-25 11:00:34 [DEBUG] mod_sofia.c:291 sofia_on_hangup() Sending CANCEL to sofia/default/417@192.168.10.150:1046;line=u83t1yyd
2008-03-25 11:00:34 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 42 (sofia/default/417@192.168.10.148:2075;line=a8pw3t1k) Ended
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/417@192.168.10.150:1046;line=u83t1yyd, cause: LOSE_RACE
2008-03-25 11:00:34 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/417@192.168.10.148:2075;line=a8pw3t1k [CS_HANGUP]
2008-03-25 11:00:34 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HANGUP going to sleep
2008-03-25 11:00:34 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 43 (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) Locked, Waiting on external entities
2008-03-25 11:00:34 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 43 (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) Ended
2008-03-25 11:00:34 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd [CS_HANGUP]
2008-03-25 11:00:34 [DEBUG] sofia.c:345 sofia_event_callback() nua_r_prack: unknown event 39: 200 Ok
2008-03-25 11:00:34 [DEBUG] sofia.c:345 sofia_event_callback() nua_r_cancel: unknown event 32: 200 OK
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_r_invite] status [487][Request Terminated] session: n/a
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [487][Request Terminated] session: n/a
2008-03-25 11:00:34 [DEBUG] sofia.c:345 sofia_event_callback() nua_r_prack: unknown event 39: 200 Ok
2008-03-25 11:00:34 [DEBUG] sofia.c:345 sofia_event_callback() nua_r_cancel: unknown event 32: 200 OK
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_r_invite] status [487][Request Terminated] session: n/a
2008-03-25 11:00:34 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [487][Request Terminated] session: n/a
2008-03-25 11:00:34 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/315@192.168.10.2:5060 entering state [ready]
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Execute voicemail(default 192.168.10.2 ${dialed_ext})
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:169 switch_core_standard_on_execute() sofia/default/315@192.168.10.2:5060 Expanded String voicemail(default 192.168.10.2 417)
2008-03-25 11:00:35 [DEBUG] switch_ivr_play_say.c:115 switch_ivr_phrase_macro() No language specified - Using [en]
2008-03-25 11:00:35 [DEBUG] switch_ivr_play_say.c:256 switch_ivr_phrase_macro() Handle say:[417] (en:en)
2008-03-25 11:00:35 [ERR] mod_sndfile.c:164 sndfile_file_open() Error Opening File [/usr/local/freeswitch/sounds/en/us/callie/digits/4.wav] [System error : No such file or directory.]
2008-03-25 11:00:35 [DEBUG] switch_ivr_play_say.c:115 switch_ivr_phrase_macro() No language specified - Using [en]
2008-03-25 11:00:35 [DEBUG] switch_ivr_play_say.c:256 switch_ivr_phrase_macro() Handle play-file:[voicemail/vm-goodbye.wav] (en:en)
2008-03-25 11:00:35 [ERR] mod_sndfile.c:164 sndfile_file_open() Error Opening File [/usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-goodbye.wav] [System error : No such file or directory.]
2008-03-25 11:00:35 [NOTICE] switch_core_state_machine.c:195 switch_core_standard_on_execute() Hangup sofia/default/315@192.168.10.2:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2008-03-25 11:00:35 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/315@192.168.10.2:5060 [KILL]
2008-03-25 11:00:35 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/315@192.168.10.2:5060 [BREAK]
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/315@192.168.10.2:5060 Running State Change CS_HANGUP
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State HANGUP
2008-03-25 11:00:35 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/315@192.168.10.2:5060 hanging up, cause: NORMAL_CLEARING
2008-03-25 11:00:35 [DEBUG] mod_sofia.c:287 sofia_on_hangup() Sending BYE to sofia/default/315@192.168.10.2:5060
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/315@192.168.10.2:5060, cause: NORMAL_CLEARING
2008-03-25 11:00:35 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/315@192.168.10.2:5060) State HANGUP going to sleep
2008-03-25 11:00:35 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 41 (sofia/default/315@192.168.10.2:5060) Locked, Waiting on external entities
2008-03-25 11:00:35 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 41 (sofia/default/315@192.168.10.2:5060) Ended
2008-03-25 11:00:35 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/315@192.168.10.2:5060 [CS_HANGUP]
2008-03-25 11:01:21 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/usr/local/freeswitch/sounds/music/8000/suite-espanola-op-47-leyenda.wav] rate 8000hz
2008-03-25 11:01:21 [DEBUG] mod_local_stream.c:186 read_stream_thread() Playing [/usr/local/freeswitch/sounds/music/8000/suite-espanola-op-47-leyenda.wav] rate: 8000hz
2008-03-25 11:01:37 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/305@192.168.10.2:5060 entering state [terminated]
2008-03-25 11:01:37 [NOTICE] sofia.c:1949 sofia_handle_sip_i_state() Hangup sofia/default/305@192.168.10.2:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2008-03-25 11:01:37 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/305@192.168.10.2:5060 [KILL]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:275 audio_bridge_thread() read: sofia/default/305@192.168.10.2:5060 Bad Frame.... Bubye!
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/305@192.168.10.2:5060 [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:269 audio_bridge_thread() write: sofia/default/305@192.168.10.2:5060 Bad Frame....[160] Bubye!
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/305@192.168.10.2:5060]
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:763 switch_ivr_multi_threaded_bridge() sofia/default/417@192.168.10.150:1046;line=u83t1yyd State Change CS_LOOPBACK -> CS_RESET
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/305@192.168.10.2:5060 [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/417@192.168.10.150:1046;line=u83t1yyd]
2008-03-25 11:01:37 [NOTICE] switch_ivr_bridge.c:374 audio_bridge_on_loopback() Hangup sofia/default/417@192.168.10.150:1046;line=u83t1yyd [CS_RESET] [NORMAL_CLEARING]
2008-03-25 11:01:37 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [KILL]
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/417@192.168.10.150:1046;line=u83t1yyd [BREAK]
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/305@192.168.10.2:5060 Running State Change CS_HANGUP
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:470 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State LOOPBACK going to sleep
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/417@192.168.10.150:1046;line=u83t1yyd Running State Change CS_HANGUP
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State HANGUP
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HANGUP
2008-03-25 11:01:37 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/305@192.168.10.2:5060 hanging up, cause: NORMAL_CLEARING
2008-03-25 11:01:37 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd hanging up, cause: NORMAL_CLEARING
2008-03-25 11:01:37 [DEBUG] mod_sofia.c:287 sofia_on_hangup() Sending BYE to sofia/default/417@192.168.10.150:1046;line=u83t1yyd
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/417@192.168.10.150:1046;line=u83t1yyd, cause: NORMAL_CLEARING
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) State HANGUP going to sleep
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 37 (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) Locked, Waiting on external entities
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/305@192.168.10.2:5060, cause: NORMAL_CLEARING
2008-03-25 11:01:37 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State HANGUP going to sleep
2008-03-25 11:01:37 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 34 (sofia/default/305@192.168.10.2:5060) Locked, Waiting on external entities
2008-03-25 11:01:37 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 37 (sofia/default/417@192.168.10.150:1046;line=u83t1yyd) Ended
2008-03-25 11:01:37 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 34 (sofia/default/305@192.168.10.2:5060) Ended
2008-03-25 11:01:37 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/305@192.168.10.2:5060 [CS_HANGUP]
2008-03-25 11:01:37 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/417@192.168.10.150:1046;line=u83t1yyd [CS_HANGUP]
2008-03-25 11:01:39 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/305@192.168.10.2:5060 entering state [received]
2008-03-25 11:01:39 [DEBUG] sofia.c:1557 sofia_handle_sip_i_state() Remote SDP:
v=0 
o=305 285669107 1962116479 IN IP4 192.168.10.105 
s=- 
c=IN IP4 192.168.10.105 
t=0 0 
m=audio 8002 RTP/AVP 98 97 8 0 3 101 
a=rtpmap:98 speex/16000 
a=rtpmap:97 speex/8000 
a=rtpmap:8 PCMA/8000 
a=rtpmap:0 PCMU/8000 
a=rtpmap:3 GSM/8000 
a=rtpmap:101 telephone-event/8000 
a=fmtp:101 0-15 
a=ptime:20 

2008-03-25 11:01:39 [DEBUG] switch_ivr_play_say.c:1121 switch_ivr_play_file() done playing file
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:160 audio_bridge_thread() Kill sofia/default/305@192.168.10.2:5060 [BREAK]
2008-03-25 11:01:39 [DEBUG] sofia_glue.c:1951 sofia_glue_negotiate_sdp() Our existing codec [PCMA] is still good, let's keep it
2008-03-25 11:01:39 [DEBUG] sofia_glue.c:1976 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-03-25 11:01:39 [DEBUG] sofia_glue.c:1525 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/305@192.168.10.2:5060] 192.168.10.2:22110->192.168.10.105:8002 codec: 8 ms: 20
2008-03-25 11:01:39 [DEBUG] sofia_glue.c:1545 sofia_glue_activate_rtp() AUDIO RTP CHANGING DEST TO: [192.168.10.105:8002]
2008-03-25 11:01:39 [DEBUG] sofia.c:1811 sofia_handle_sip_i_state() Processing Reinvite
2008-03-25 11:01:39 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/305@192.168.10.2:5060 entering state [completed]
2008-03-25 11:01:39 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/305@192.168.10.2:5060 entering state [ready]
2008-03-25 11:01:39 [DEBUG] sofia.c:1553 sofia_handle_sip_i_state() Channel sofia/default/305@192.168.10.2:5060 entering state [terminated]
2008-03-25 11:01:39 [NOTICE] sofia.c:1949 sofia_handle_sip_i_state() Hangup sofia/default/305@192.168.10.2:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2008-03-25 11:01:39 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/305@192.168.10.2:5060 [KILL]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:275 audio_bridge_thread() read: sofia/default/305@192.168.10.2:5060 Bad Frame.... Bubye!
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/305@192.168.10.2:5060 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/305@192.168.10.2:5060]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:763 switch_ivr_multi_threaded_bridge() sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 State Change CS_LOOPBACK -> CS_RESET
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:467 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State EXECUTE going to sleep
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/305@192.168.10.2:5060 Running State Change CS_HANGUP
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:269 audio_bridge_thread() write: sofia/default/305@192.168.10.2:5060 Bad Frame....[160] Bubye!
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/305@192.168.10.2:5060 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/317@192.168.10.148:2075;line=wrxhnyi6]
2008-03-25 11:01:39 [NOTICE] switch_ivr_bridge.c:374 audio_bridge_on_loopback() Hangup sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [CS_RESET] [NORMAL_CLEARING]
2008-03-25 11:01:39 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [KILL]
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [BREAK]
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:470 switch_core_session_run() (sofia/default/317@192.168.10.148:2075;line=wrxhnyi6) State LOOPBACK going to sleep
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:403 switch_core_session_run() sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 Running State Change CS_HANGUP
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/317@192.168.10.148:2075;line=wrxhnyi6) State HANGUP
2008-03-25 11:01:39 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 hanging up, cause: NORMAL_CLEARING
2008-03-25 11:01:39 [DEBUG] mod_sofia.c:287 sofia_on_hangup() Sending BYE to sofia/default/317@192.168.10.148:2075;line=wrxhnyi6
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/317@192.168.10.148:2075;line=wrxhnyi6, cause: NORMAL_CLEARING
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/317@192.168.10.148:2075;line=wrxhnyi6) State HANGUP going to sleep
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 33 (sofia/default/317@192.168.10.148:2075;line=wrxhnyi6) Locked, Waiting on external entities
2008-03-25 11:01:39 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 33 (sofia/default/317@192.168.10.148:2075;line=wrxhnyi6) Ended
2008-03-25 11:01:39 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/317@192.168.10.148:2075;line=wrxhnyi6 [CS_HANGUP]
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State HANGUP
2008-03-25 11:01:39 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/305@192.168.10.2:5060 hanging up, cause: NORMAL_CLEARING
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/305@192.168.10.2:5060, cause: NORMAL_CLEARING
2008-03-25 11:01:39 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/305@192.168.10.2:5060) State HANGUP going to sleep
2008-03-25 11:01:39 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 30 (sofia/default/305@192.168.10.2:5060) Locked, Waiting on external entities
2008-03-25 11:01:39 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 30 (sofia/default/305@192.168.10.2:5060) Ended
2008-03-25 11:01:39 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/305@192.168.10.2:5060 [CS_HANGUP]