2008-03-07 08:48:59 [DEBUG] sofia.c:221 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a
2008-03-07 08:48:59 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/1000@192.168.1.95:5060 [babf8a9b-4d64-48d4-b3a5-e3be737b4f12]
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/1000@192.168.1.95:5060 Running State Change CS_NEW
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/1000@192.168.1.95:5060) State NEW
2008-03-07 08:48:59 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/1000@192.168.1.95:5060 entering state [received]
2008-03-07 08:48:59 [DEBUG] sofia.c:1477 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 1204915377 1204915377 IN IP4 192.168.1.99
s=Opal SIP Session
c=IN IP4 192.168.1.99
t=0 0
m=audio 5014 RTP/AVP 0 114 115 3 107 110 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:114 SPEEX/16000
a=rtpmap:115 iLBC/8000
a=rtpmap:3 GSM/8000
a=rtpmap:107 MS-GSM/8000
a=rtpmap:110 SPEEX/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 5016 RTP/AVP 31
a=rtpmap:31 H261/90000

2008-03-07 08:48:59 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[G722:9:8000]
2008-03-07 08:48:59 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2008-03-07 08:48:59 [DEBUG] sofia_glue.c:1298 sofia_glue_tech_set_codec() Set Codec sofia/default/1000@192.168.1.95:5060 PCMU/8000 20 ms 160 samples
2008-03-07 08:48:59 [DEBUG] sofia_glue.c:1924 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-03-07 08:48:59 [DEBUG] sofia_glue.c:2074 sofia_glue_negotiate_sdp() Video Codec Compare [H261:31]/[H263:34]
2008-03-07 08:48:59 [DEBUG] sofia.c:1614 sofia_handle_sip_i_state() sofia/default/1000@192.168.1.95:5060 State Change CS_NEW -> CS_INIT
2008-03-07 08:48:59 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/1000@192.168.1.95:5060 [BREAK]
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/1000@192.168.1.95:5060 Running State Change CS_INIT
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:442 switch_core_session_run() (sofia/default/1000@192.168.1.95:5060) State INIT
2008-03-07 08:48:59 [DEBUG] mod_sofia.c:82 sofia_on_init() sofia/default/1000@192.168.1.95:5060 SOFIA INIT
2008-03-07 08:48:59 [DEBUG] mod_sofia.c:108 sofia_on_init() sofia/default/1000@192.168.1.95:5060 State Change CS_INIT -> CS_RING
2008-03-07 08:48:59 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/1000@192.168.1.95:5060 [BREAK]
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/1000@192.168.1.95:5060 Running State Change CS_RING
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:447 switch_core_session_run() (sofia/default/1000@192.168.1.95:5060) State RING
2008-03-07 08:48:59 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/1000@192.168.1.95:5060 SOFIA RING
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/1000@192.168.1.95:5060
2008-03-07 08:48:59 [INFO] mod_dialplan_xml.c:222 dialplan_hunt() Processing Steve Yannalfo->9996@default
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(0848) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^886$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^\*\*(\d+)$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^870$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.1.99) =~ /^$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}() =~ /^$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [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-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^88(.*)$|^\*0(.*)$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^\*69$|^869$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^80(\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^81(\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^82(\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^83(\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^8(10[01][0-9])$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^(10[01][0-9])$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^sip:(.*)$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^(30\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^(31\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^(32\d{2})$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^9(888|1616)$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /5000/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^pagegroup$|^7243/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^5900$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^5901$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions source(mod_sofia) =~ /mod_sofia/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /park\+(\d+)/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions source(mod_sofia) =~ /mod_sofia/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^parking$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^9993$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^9994$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^9995$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(9996) =~ /^9996$/
2008-03-07 08:48:59 [DEBUG] mod_dialplan_xml.c:278 dialplan_hunt() sofia/default/1000@192.168.1.95:5060 State Change CS_RING -> CS_EXECUTE
2008-03-07 08:48:59 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/1000@192.168.1.95:5060 [BREAK]
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/1000@192.168.1.95:5060 Running State Change CS_EXECUTE
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/1000@192.168.1.95:5060) State EXECUTE
2008-03-07 08:48:59 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/1000@192.168.1.95:5060 SOFIA EXECUTE
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Expanded String set(use_profile=nat)
2008-03-07 08:48:59 [DEBUG] mod_dptools.c:417 set_function() SET [use_profile]=[nat]
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute set_user(default@${domain})
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Expanded String set_user(default@192.168.1.95)
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Expanded String db(insert/spymap/1000/babf8a9b-4d64-48d4-b3a5-e3be737b4f12)
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Expanded String db(insert/last_dial/1000/9996)
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Expanded String db(insert/last_dial/global/babf8a9b-4d64-48d4-b3a5-e3be737b4f12)
2008-03-07 08:48:59 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute answer()
2008-03-07 08:48:59 [DEBUG] sofia_glue.c:1481 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/1000@192.168.1.95:5060] 192.168.1.95:20358->192.168.1.99:5014 codec: 0 ms: 20
2008-03-07 08:48:59 [DEBUG] switch_rtp.c:715 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2008-03-07 08:49:00 [DEBUG] mod_sofia.c:380 sofia_answer_channel() Local SDP sofia/default/1000@192.168.1.95:5060:
v=0
o=FreeSWITCH 1204877381 1204877382 IN IP4 192.168.1.95
s=FreeSWITCH
c=IN IP4 192.168.1.95
t=0 0
a=sendrecv
m=audio 20358 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
m=video 23942 RTP/AVP 34
a=rtpmap:34 H263/90000

2008-03-07 08:49:00 [DEBUG] switch_core_session.c:368 switch_core_session_receive_message() Kill sofia/default/1000@192.168.1.95:5060 [BREAK]
2008-03-07 08:49:00 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/1000@192.168.1.95:5060 entering state [completed]
2008-03-07 08:49:00 [NOTICE] mod_dptools.c:358 answer_function() Channel [sofia/default/1000@192.168.1.95:5060] has been answered
2008-03-07 08:49:00 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/1000@192.168.1.95:5060 entering state [ready]
2008-03-07 08:49:00 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute echo()