All pastes #932411 Raw Edit
freeswitch video conference

public text v1 · immutable
·published 2008-03-07 18:46 UTC
2008-03-07 08:45:17 [DEBUG] sofia.c:221 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a
2008-03-07 08:45:17 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/1000@192.168.1.95:5060 [69eb08a1-fe3f-4c49-afde-db601df943e9]
2008-03-07 08:45:17 [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:45:17 [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:45:17 [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:45:17 [DEBUG] sofia.c:1477 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 1204915154 1204915154 IN IP4 192.168.1.99
s=Opal SIP Session
c=IN IP4 192.168.1.99
t=0 0
m=audio 5010 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 5012 RTP/AVP 31
a=rtpmap:31 H261/90000

2008-03-07 08:45:17 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[G722:9:8000]
2008-03-07 08:45:17 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2008-03-07 08:45:17 [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:45:17 [DEBUG] sofia_glue.c:1924 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-03-07 08:45:17 [DEBUG] sofia_glue.c:2074 sofia_glue_negotiate_sdp() Video Codec Compare [H261:31]/[H263:34]
2008-03-07 08:45:17 [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:45:17 [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:45:17 [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:45:17 [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:45:17 [DEBUG] mod_sofia.c:82 sofia_on_init() sofia/default/1000@192.168.1.95:5060 SOFIA INIT
2008-03-07 08:45:17 [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:45:17 [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:45:17 [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:45:17 [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:45:17 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/1000@192.168.1.95:5060 SOFIA RING
2008-03-07 08:45:17 [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:45:17 [INFO] mod_dialplan_xml.c:222 dialplan_hunt() Processing Steve Yannalfo->3000@default
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(0845) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^886$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^\*\*(\d+)$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^870$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.1.99) =~ /^$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}() =~ /^$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [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:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^88(.*)$|^\*0(.*)$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^\*69$|^869$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^80(\d{2})$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^81(\d{2})$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^82(\d{2})$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^83(\d{2})$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^8(10[01][0-9])$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^(10[01][0-9])$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^sip:(.*)$/
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:45:17 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^(30\d{2})$/
2008-03-07 08:45:17 [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:45:17 [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:45:17 [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:45:17 [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:45:17 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/1000@192.168.1.95:5060 SOFIA EXECUTE
2008-03-07 08:45:17 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE
2008-03-07 08:45:17 [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:45:17 [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:45:17 [DEBUG] mod_dptools.c:417 set_function() SET [use_profile]=[nat]
2008-03-07 08:45:17 [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:45:17 [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:45:17 [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:45:17 [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/69eb08a1-fe3f-4c49-afde-db601df943e9)
2008-03-07 08:45:17 [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:45:17 [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/3000)
2008-03-07 08:45:17 [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:45:17 [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/69eb08a1-fe3f-4c49-afde-db601df943e9)
2008-03-07 08:45:17 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/1000@192.168.1.95:5060 Execute conference(3000@default)
2008-03-07 08:45:17 [DEBUG] switch_core_state_machine.c:162 switch_core_standard_on_execute() Application conference Requires media! pre_answering channel sofia/default/1000@192.168.1.95:5060
2008-03-07 08:45:17 [INFO] mod_sofia.c:1002 sofia_receive_message() Asked to send early media by sofia/default/1000@192.168.1.95:5060
2008-03-07 08:45:17 [DEBUG] sofia_glue.c:1481 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/1000@192.168.1.95:5060] 192.168.1.95:27678->192.168.1.99:5010 codec: 0 ms: 20
2008-03-07 08:45:17 [DEBUG] switch_rtp.c:715 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2008-03-07 08:45:17 [INFO] mod_sofia.c:1044 sofia_receive_message() Ring SDP:
v=0
o=FreeSWITCH 1204869839 1204869840 IN IP4 192.168.1.95
s=FreeSWITCH
c=IN IP4 192.168.1.95
t=0 0
a=sendrecv
m=audio 27678 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 28930 RTP/AVP 34
a=rtpmap:34 H263/90000

2008-03-07 08:45:17 [NOTICE] switch_channel.c:1383 switch_channel_perform_mark_pre_answered() Ring-Ready sofia/default/1000@192.168.1.95:5060!
2008-03-07 08:45:17 [NOTICE] mod_sofia.c:1047 sofia_receive_message() Pre-Answer sofia/default/1000@192.168.1.95:5060!
2008-03-07 08:45:17 [DEBUG] sofia.c:221 sofia_event_callback() event [nua_i_state] status [183][Session Progress] session: sofia/default/1000@192.168.1.95:5060
2008-03-07 08:45:17 [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:45:17 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/1000@192.168.1.95:5060 entering state [early]
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'mute' bound to '0'.
2008-03-07 08:45:17 [DEBUG] switch_ivr.c:1085 switch_ivr_digit_stream_parser_set_event() max len 1
2008-03-07 08:45:17 [DEBUG] switch_ivr.c:1089 switch_ivr_digit_stream_parser_set_event() min len 1
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'deaf mute' bound to '*'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'energy up' bound to '9'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'energy equ' bound to '8'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'energy dn' bound to '7'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol talk up' bound to '3'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol talk zero' bound to '2'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol talk dn' bound to '1'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol listen up' bound to '6'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol listen zero' bound to '5'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'vol listen dn' bound to '4'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4542 conf_default_controls() Installing default caller control action 'hangup' bound to '#'.
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4255 conference_function() Raw Codec Activation Success L16@8000hz 1 channel 20ms
2008-03-07 08:45:17 [DEBUG] mod_conference.c:4302 conference_function() Raw Codec Activation Success L16@8000hz 1 channel 20ms
2008-03-07 08:45:17 [DEBUG] mod_conference.c:832 conference_thread_run() setup timer success interval: 20  samples: 160
2008-03-07 08:45:17 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/usr/local/freeswitch/sounds/en/us/callie/conference/8000/conf-alone.wav] rate 8000hz
2008-03-07 08:45:17 [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:45:17 [DEBUG] mod_conference.c:1666 conference_loop_output() setup timer soft success interval: 20  samples: 160
2008-03-07 08:45:17 [DEBUG] mod_conference.c:1755 conference_loop_output() CLFAG_ANSWERED set, answering inbound channel
2008-03-07 08:45:17 [DEBUG] mod_sofia.c:380 sofia_answer_channel() Local SDP sofia/default/1000@192.168.1.95:5060:
v=0
o=FreeSWITCH 1204869839 1204869841 IN IP4 192.168.1.95
s=FreeSWITCH
c=IN IP4 192.168.1.95
t=0 0
a=sendrecv
m=audio 27678 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 28930 RTP/AVP 34
a=rtpmap:34 H263/90000

2008-03-07 08:45:17 [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:45:17 [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:45:17 [NOTICE] mod_conference.c:1756 conference_loop_output() Channel [sofia/default/1000@192.168.1.95:5060] has been answered
2008-03-07 08:45:17 [DEBUG] mod_local_stream.c:281 local_stream_file_open() Opening Stream [moh/8000] 8000hz
2008-03-07 08:45:17 [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:45:17 [DEBUG] switch_core_io.c:325 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes
2008-03-07 08:45:20 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [107@192.168.1.95]
2008-03-07 08:45:20 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [107@192.168.1.95]
2008-03-07 08:45:27 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [104@192.168.1.95]
2008-03-07 08:45:27 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [104@192.168.1.95]
2008-03-07 08:45:27 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [105@192.168.1.95]
2008-03-07 08:45:27 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [105@192.168.1.95]
2008-03-07 08:45:29 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [101@192.168.1.95]
2008-03-07 08:45:29 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [101@192.168.1.95]
2008-03-07 08:45:36 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [107@192.168.1.95]
2008-03-07 08:45:36 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [107@192.168.1.95]
2008-03-07 08:45:43 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [104@192.168.1.95]
2008-03-07 08:45:43 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [104@192.168.1.95]
2008-03-07 08:45:43 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [105@192.168.1.95]
2008-03-07 08:45:43 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [105@192.168.1.95]
2008-03-07 08:45:44 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [101@192.168.1.95]
2008-03-07 08:45:44 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [101@192.168.1.95]
2008-03-07 08:45:52 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [107@192.168.1.95]
2008-03-07 08:45:52 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [107@192.168.1.95]
2008-03-07 08:45:59 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [104@192.168.1.95]
2008-03-07 08:45:59 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [104@192.168.1.95]
2008-03-07 08:45:59 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [105@192.168.1.95]
2008-03-07 08:45:59 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [105@192.168.1.95]
2008-03-07 08:45:59 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [101@192.168.1.95]
2008-03-07 08:45:59 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [101@192.168.1.95]
2008-03-07 08:46:08 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [107@192.168.1.95]
2008-03-07 08:46:08 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [107@192.168.1.95]
2008-03-07 08:46:14 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [101@192.168.1.95]
2008-03-07 08:46:14 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [101@192.168.1.95]
2008-03-07 08:46:14 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [104@192.168.1.95]
2008-03-07 08:46:14 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [104@192.168.1.95]
2008-03-07 08:46:14 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [105@192.168.1.95]
2008-03-07 08:46:14 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [105@192.168.1.95]
2008-03-07 08:46:25 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [107@192.168.1.95]
2008-03-07 08:46:25 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [107@192.168.1.95]
2008-03-07 08:46:29 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [101@192.168.1.95]
2008-03-07 08:46:29 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [101@192.168.1.95]
2008-03-07 08:46:30 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [104@192.168.1.95]
2008-03-07 08:46:30 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [104@192.168.1.95]
2008-03-07 08:46:30 [WARNING] sofia_reg.c:894 sofia_reg_parse_auth() can't find user [105@192.168.1.95]
2008-03-07 08:46:30 [DEBUG] sofia_reg.c:484 sofia_reg_handle_register() send challange for [105@192.168.1.95]
2008-03-07 08:46:33 [DEBUG] sofia.c:221 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a
2008-03-07 08:46:33 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/102@192.168.1.95:5060 [47af19fa-301a-456a-abbf-56b447a1c99e]
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/102@192.168.1.95:5060 Running State Change CS_NEW
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/102@192.168.1.95:5060) State NEW
2008-03-07 08:46:33 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/102@192.168.1.95:5060 entering state [received]
2008-03-07 08:46:33 [DEBUG] sofia.c:1477 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 1204915522 1204915522 IN IP4 192.168.1.100
s=Opal SIP Session
c=IN IP4 192.168.1.100
t=0 0
m=audio 5038 RTP/AVP 114 115 3 107 110 0 8 101
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:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 5040 RTP/AVP 31
a=rtpmap:31 H261/90000

2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:114:16000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:114:16000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [iLBC:115:8000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [iLBC:115:8000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [GSM:3:8000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [GSM:3:8000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [MS-GSM:107:8000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [MS-GSM:107:8000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:110:8000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:110:8000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[G722:9:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1960 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1298 sofia_glue_tech_set_codec() Set Codec sofia/default/102@192.168.1.95:5060 PCMU/8000 20 ms 160 samples
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1924 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:2074 sofia_glue_negotiate_sdp() Video Codec Compare [H261:31]/[H263:34]
2008-03-07 08:46:33 [DEBUG] sofia.c:1614 sofia_handle_sip_i_state() sofia/default/102@192.168.1.95:5060 State Change CS_NEW -> CS_INIT
2008-03-07 08:46:33 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/102@192.168.1.95:5060 Running State Change CS_INIT
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:442 switch_core_session_run() (sofia/default/102@192.168.1.95:5060) State INIT
2008-03-07 08:46:33 [DEBUG] mod_sofia.c:82 sofia_on_init() sofia/default/102@192.168.1.95:5060 SOFIA INIT
2008-03-07 08:46:33 [DEBUG] mod_sofia.c:108 sofia_on_init() sofia/default/102@192.168.1.95:5060 State Change CS_INIT -> CS_RING
2008-03-07 08:46:33 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/102@192.168.1.95:5060 Running State Change CS_RING
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:447 switch_core_session_run() (sofia/default/102@192.168.1.95:5060) State RING
2008-03-07 08:46:33 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/102@192.168.1.95:5060 SOFIA RING
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/102@192.168.1.95:5060
2008-03-07 08:46:33 [INFO] mod_dialplan_xml.c:222 dialplan_hunt() Processing Unknown->3000@default
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(0846) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^886$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^\*\*(\d+)$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^870$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(192.168.1.100) =~ /^$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}() =~ /^$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [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:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^88(.*)$|^\*0(.*)$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^\*69$|^869$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^80(\d{2})$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^81(\d{2})$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^82(\d{2})$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^83(\d{2})$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^8(10[01][0-9])$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^(10[01][0-9])$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^sip:(.*)$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(3000) =~ /^(30\d{2})$/
2008-03-07 08:46:33 [DEBUG] mod_dialplan_xml.c:278 dialplan_hunt() sofia/default/102@192.168.1.95:5060 State Change CS_RING -> CS_EXECUTE
2008-03-07 08:46:33 [DEBUG] switch_core_session.c:655 switch_core_session_signal_state_change() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:409 switch_core_session_run() sofia/default/102@192.168.1.95:5060 Running State Change CS_EXECUTE
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:457 switch_core_session_run() (sofia/default/102@192.168.1.95:5060) State EXECUTE
2008-03-07 08:46:33 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/102@192.168.1.95:5060 SOFIA EXECUTE
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute set(use_profile=${cond(${is_lan_addr(${network_addr})} == yes ? nat : default)})
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Expanded String set(use_profile=nat)
2008-03-07 08:46:33 [DEBUG] mod_dptools.c:417 set_function() SET [use_profile]=[nat]
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute set_user(default@${domain})
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Expanded String set_user(default@192.168.1.95)
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Expanded String db(insert/spymap/102/47af19fa-301a-456a-abbf-56b447a1c99e)
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Expanded String db(insert/last_dial/102/3000)
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute db(insert/last_dial/global/${uuid})
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:170 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Expanded String db(insert/last_dial/global/47af19fa-301a-456a-abbf-56b447a1c99e)
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:142 switch_core_standard_on_execute() sofia/default/102@192.168.1.95:5060 Execute conference(3000@default)
2008-03-07 08:46:33 [DEBUG] switch_core_state_machine.c:162 switch_core_standard_on_execute() Application conference Requires media! pre_answering channel sofia/default/102@192.168.1.95:5060
2008-03-07 08:46:33 [INFO] mod_sofia.c:1002 sofia_receive_message() Asked to send early media by sofia/default/102@192.168.1.95:5060
2008-03-07 08:46:33 [DEBUG] sofia_glue.c:1481 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/102@192.168.1.95:5060] 192.168.1.95:31432->192.168.1.100:5038 codec: 0 ms: 20
2008-03-07 08:46:33 [DEBUG] switch_rtp.c:715 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2008-03-07 08:46:33 [INFO] mod_sofia.c:1044 sofia_receive_message() Ring SDP:
v=0
o=FreeSWITCH 1204866161 1204866162 IN IP4 192.168.1.95
s=FreeSWITCH
c=IN IP4 192.168.1.95
t=0 0
a=sendrecv
m=audio 31432 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 27076 RTP/AVP 34
a=rtpmap:34 H263/90000

2008-03-07 08:46:33 [NOTICE] switch_channel.c:1383 switch_channel_perform_mark_pre_answered() Ring-Ready sofia/default/102@192.168.1.95:5060!
2008-03-07 08:46:33 [NOTICE] mod_sofia.c:1047 sofia_receive_message() Pre-Answer sofia/default/102@192.168.1.95:5060!
2008-03-07 08:46:33 [DEBUG] sofia.c:221 sofia_event_callback() event [nua_i_state] status [183][Session Progress] session: sofia/default/102@192.168.1.95:5060
2008-03-07 08:46:33 [DEBUG] switch_core_session.c:368 switch_core_session_receive_message() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/102@192.168.1.95:5060 entering state [early]
2008-03-07 08:46:33 [DEBUG] mod_conference.c:4255 conference_function() Raw Codec Activation Success L16@8000hz 1 channel 20ms
2008-03-07 08:46:33 [DEBUG] mod_conference.c:4302 conference_function() Raw Codec Activation Success L16@8000hz 1 channel 20ms
2008-03-07 08:46:33 [DEBUG] switch_core_session.c:368 switch_core_session_receive_message() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] mod_conference.c:1666 conference_loop_output() setup timer soft success interval: 20  samples: 160
2008-03-07 08:46:33 [DEBUG] mod_conference.c:1755 conference_loop_output() CLFAG_ANSWERED set, answering inbound channel
2008-03-07 08:46:33 [DEBUG] mod_sofia.c:380 sofia_answer_channel() Local SDP sofia/default/102@192.168.1.95:5060:
v=0
o=FreeSWITCH 1204866161 1204866163 IN IP4 192.168.1.95
s=FreeSWITCH
c=IN IP4 192.168.1.95
t=0 0
a=sendrecv
m=audio 31432 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 27076 RTP/AVP 34
a=rtpmap:34 H263/90000

2008-03-07 08:46:33 [DEBUG] switch_core_session.c:368 switch_core_session_receive_message() Kill sofia/default/102@192.168.1.95:5060 [BREAK]
2008-03-07 08:46:33 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/102@192.168.1.95:5060 entering state [completed]
2008-03-07 08:46:33 [NOTICE] mod_conference.c:1756 conference_loop_output() Channel [sofia/default/102@192.168.1.95:5060] has been answered
2008-03-07 08:46:33 [DEBUG] sofia.c:1473 sofia_handle_sip_i_state() Channel sofia/default/102@192.168.1.95:5060 entering state [ready]