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]