freeswitch@mark-e40edd7b44> 2008-12-16 01:45:36 [DEBUG] sofia.c:3447 sofia_handle_sip_i_invite() IP 10.0.0.2 Rejected by acl domains. Falling back to Digest auth.
2008-12-16 01:45:36 [DEBUG] sofia.c:3447 sofia_handle_sip_i_invite() IP 10.0.0.2 Rejected by acl domains. Falling back to Digest auth.
2008-12-16 01:45:36 [NOTICE] switch_channel.c:553 switch_channel_set_name() New Channel sofia/internal/1000@10.0.0.2 [22eb7482-e12b-4d4a-9d5e-cb67e5ee8934]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [received]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/1000@10.0.0.2) Running State Change CS_NEW
2008-12-16 01:45:36 [DEBUG] sofia.c:2273 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 9 2 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 59082 RTP/AVP 107 119 100 106 0 105 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : cEwejOsQ L8PAq40i 10.0.0.2 59082

2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:371 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State NEW
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32:107:16000]/[G722:9:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32:107:16000]/[PCMU:0:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32:107:16000]/[PCMA:8:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32:107:16000]/[GSM:3:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32-FEC:119:16000]/[G722:9:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32-FEC:119:16000]/[PCMU:0:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32-FEC:119:16000]/[PCMA:8:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [BV32-FEC:119:16000]/[GSM:3:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[G722:9:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[PCMU:0:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[PCMA:8:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[GSM:3:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[G722:9:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[PCMU:0:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[PCMA:8:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[GSM:3:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[G722:9:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2361 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1570 sofia_glue_tech_set_codec() Set Codec sofia/internal/1000@10.0.0.2 PCMU/8000 20 ms 160 samples
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:2325 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-12-16 01:45:36 [DEBUG] sofia.c:2414 sofia_handle_sip_i_state() (sofia/internal/1000@10.0.0.2) State Change CS_NEW -> CS_INIT
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/1000@10.0.0.2) Running State Change CS_INIT
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State INIT
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/internal/1000@10.0.0.2 SOFIA INIT
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:107 sofia_on_init() (sofia/internal/1000@10.0.0.2) State Change CS_INIT -> CS_ROUTING
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State INIT going to sleep
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/1000@10.0.0.2) Running State Change CS_ROUTING
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:422 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State ROUTING
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:121 sofia_on_routing() sofia/internal/1000@10.0.0.2 SOFIA ROUTING
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_routing() sofia/internal/1000@10.0.0.2 Standard ROUTING
2008-12-16 01:45:36 [INFO] mod_dialplan_xml.c:233 dialplan_hunt() Processing 1000->2007 in context default
2008-12-16 01:45:36 [DEBUG] mod_dialplan_xml.c:117 parse_exten() Regex: [Doctors Office] destination_number(2007) =~ /^2007$/
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:97 switch_core_standard_on_routing() (sofia/internal/1000@10.0.0.2) State Change CS_ROUTING -> CS_EXECUTE
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:422 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State ROUTING going to sleep
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/1000@10.0.0.2) Running State Change CS_EXECUTE
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:432 switch_core_session_run() (sofia/internal/1000@10.0.0.2) State EXECUTE
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:164 sofia_on_execute() sofia/internal/1000@10.0.0.2 SOFIA EXECUTE
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Standard EXECUTE
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:144 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Execute info()
2008-12-16 01:45:36 [INFO] mod_dptools.c:902 info_function() CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/1000@10.0.0.2]
Unique-ID: [22eb7482-e12b-4d4a-9d5e-cb67e5ee8934]
Call-Direction: [inbound]
Answer-State: [ringing]
Channel-Read-Codec-Name: [PCMU]
Channel-Read-Codec-Rate: [8000]
Channel-Write-Codec-Name: [PCMU]
Channel-Write-Codec-Rate: [8000]
Caller-Username: [1000]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [1000]
Caller-Caller-ID-Number: [1000]
Caller-Network-Addr: [10.0.0.2]
Caller-Destination-Number: [2007]
Caller-Unique-ID: [22eb7482-e12b-4d4a-9d5e-cb67e5ee8934]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/1000@10.0.0.2]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1229420736500000]
Caller-Channel-Created-Time: [1229420736500000]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_sip_received_ip: [10.0.0.2]
variable_sip_received_port: [59034]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_mailbox: [1000]
variable_sip_auth_username: [1000]
variable_sip_auth_realm: [10.0.0.2]
variable_mailbox: [1000]
variable_user_name: [1000]
variable_domain_name: [10.0.0.2]
variable_record_stereo: [true]
variable_default_gateway: [provider.com]
variable_default_areacode: [918]
variable_transfer_fallback_extension: [operator]
variable_toll_allow: [domestic,international,local]
variable_accountcode: [1000]
variable_user_context: [default]
variable_effective_caller_id_name: [Extension 1000]
variable_effective_caller_id_number: [1000]
variable_outbound_caller_id_name: [FreeSWITCH]
variable_outbound_caller_id_number: [0000000000]
variable_callgroup: [techsupport]
variable_sip_from_user: [1000]
variable_sip_from_uri: [1000@10.0.0.2]
variable_sip_from_host: [10.0.0.2]
variable_sip_from_user_stripped: [1000]
variable_sip_from_tag: [1346a24e]
variable_sofia_profile_name: [internal]
variable_sip_req_user: [2007]
variable_sip_req_uri: [2007@10.0.0.2]
variable_sip_req_host: [10.0.0.2]
variable_sip_to_user: [2007]
variable_sip_to_uri: [2007@10.0.0.2]
variable_sip_to_host: [10.0.0.2]
variable_sip_contact_user: [1000]
variable_sip_contact_port: [59034]
variable_sip_contact_uri: [1000@127.0.0.1:59034]
variable_sip_contact_host: [127.0.0.1]
variable_channel_name: [sofia/internal/1000@10.0.0.2]
variable_sip_call_id: [NzMxYmM5OTNhNjUzYjE3NjY5M2MxNDIwZGFjYWQ3NmI.]
variable_sip_user_agent: [X-Lite release 1100l stamp 47546]
variable_sip_via_host: [127.0.0.1]
variable_sip_via_port: [59034]
variable_sip_via_rport: [59034]
variable_max_forwards: [70]
variable_presence_id: [1000@10.0.0.2]
variable_switch_r_sdp: [v=0
o=- 9 2 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 59082 RTP/AVP 107 119 100 106 0 105 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : cEwejOsQ L8PAq40i 10.0.0.2 59082
]
variable_remote_media_ip: [10.0.0.2]
variable_remote_media_port: [59082]
variable_read_codec: [PCMU]
variable_read_rate: [8000]
variable_write_codec: [PCMU]
variable_write_rate: [8000]
variable_endpoint_disposition: [RECEIVED]
variable_current_application: [info]


2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:144 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Execute set(ringback=${us-ring})
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:1130 switch_core_session_execute_application() sofia/internal/1000@10.0.0.2 Expanded String set(ringback=%(2000, 4000, 440.0, 480.
0))
2008-12-16 01:45:36 [DEBUG] mod_dptools.c:704 set_function() sofia/internal/1000@10.0.0.2 SET [ringback]=[%(2000, 4000, 440.0, 480.0)]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:144 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Execute set(no_media=true)
2008-12-16 01:45:36 [DEBUG] mod_dptools.c:704 set_function() sofia/internal/1000@10.0.0.2 SET [no_media]=[true]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:144 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Execute set(proxy_media=true)
2008-12-16 01:45:36 [DEBUG] mod_dptools.c:704 set_function() sofia/internal/1000@10.0.0.2 SET [proxy_media]=[true]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:144 switch_core_standard_on_execute() sofia/internal/1000@10.0.0.2 Execute bridge(sofia/internal/sip:Doctorsoffice@127.0.0.1
:5068)
2008-12-16 01:45:36 [NOTICE] switch_channel.c:553 switch_channel_set_name() New Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [2259e7e0-0d77-a444-aed9-c86252d77e78]
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:2134 sofia_outgoing_channel() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State Change CS_NEW -> CS_INIT
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) Running State Change CS_INIT
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State INIT
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 SOFIA INIT
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1005 sofia_glue_tech_patch_sdp() sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 Patched SDP
---
v=0
o=- 9 2 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 59082 RTP/AVP 107 119 100 106 0 105 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : cEwejOsQ L8PAq40i 10.0.0.2 59082

+++
v=0
o=- 9 2 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 27200 RTP/AVP 107 119 100 106 0 105 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : cEwejOsQ L8PAq40i 10.0.0.2 59082

2008-12-16 01:45:36 [DEBUG] mod_sofia.c:107 sofia_on_init() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State Change CS_INIT -> CS_ROUTING
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State INIT going to sleep
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) Running State Change CS_ROUTING
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:422 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State ROUTING
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:121 sofia_on_routing() sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 SOFIA ROUTING
2008-12-16 01:45:36 [DEBUG] switch_ivr_originate.c:58 originate_on_routing() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:422 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State ROUTING going to sleep
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) Running State Change CS_CONSUME_MEDIA
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [calling]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:444 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State CONSUME_MEDIA
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [proceeding]
2008-12-16 01:45:36 [NOTICE] sofia.c:2311 sofia_handle_sip_i_state() Ring-Ready sofia/internal/sip:Doctorsoffice@127.0.0.1:5068!
2008-12-16 01:45:36 [NOTICE] mod_sofia.c:1125 sofia_receive_message() Ring-Ready sofia/internal/1000@10.0.0.2!
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [NOTICE] switch_ivr_originate.c:1304 switch_ivr_originate() Ring Ready sofia/internal/1000@10.0.0.2!
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [early]
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [ready]
2008-12-16 01:45:36 [DEBUG] sofia.c:2273 sofia_handle_sip_i_state() Remote SDP:
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 10.0.0.2
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10012 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1005 sofia_glue_tech_patch_sdp() sofia/internal/1000@10.0.0.2 Patched SDP
---
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 10.0.0.2
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10012 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

+++
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 10.0.0.2
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 27202 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1829 sofia_glue_activate_rtp() PROXY AUDIO RTP [sofia/internal/1000@10.0.0.2] 10.0.0.2:27202->10.0.0.2:59082 codec: 0 ms: 20
2008-12-16 01:45:36 [DEBUG] switch_channel.c:1665 switch_channel_perform_mark_answered() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [NOTICE] sofia.c:2669 sofia_handle_sip_i_state() Channel [sofia/internal/sip:Doctorsoffice@127.0.0.1:5068] has been answered
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1570 sofia_glue_tech_set_codec() Set Codec sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 PROXY/8000 20 ms 160 samples
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1829 sofia_glue_activate_rtp() PROXY AUDIO RTP [sofia/internal/sip:Doctorsoffice@127.0.0.1:5068] 10.0.0.2:27200->10.0.0.2:10012 codec: 0 ms
: 20
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1957 sofia_glue_activate_rtp() Set comfort noise payload to 13
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [completed]
2008-12-16 01:45:36 [NOTICE] switch_ivr_originate.c:1494 switch_ivr_originate() Channel [sofia/internal/1000@10.0.0.2] has been answered
2008-12-16 01:45:36 [DEBUG] switch_ivr_originate.c:1534 switch_ivr_originate() Originate Resulted in Success: [sofia/internal/sip:Doctorsoffice@127.0.0.1:5068]
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_ivr_bridge.c:874 switch_ivr_multi_threaded_bridge() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State Change CS_CONSUME_MEDIA -> CS_EXCHANG
E_MEDIA
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:444 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State CONSUME_MEDIA going to sleep
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) Running State Change CS_EXCHANGE_MEDIA
2008-12-16 01:45:36 [DEBUG] switch_core_state_machine.c:435 switch_core_session_run() (sofia/internal/sip:Doctorsoffice@127.0.0.1:5068) State EXCHANGE_MEDIA
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:377 sofia_on_exchange_media() SOFIA LOOPBACK
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [received]
2008-12-16 01:45:36 [DEBUG] sofia.c:2273 sofia_handle_sip_i_state() Remote SDP:
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 127.0.0.1
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10016 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] sofia.c:2564 sofia_handle_sip_i_state() Passing SDP to other leg.
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 127.0.0.1
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10016 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] mod_sofia.c:889 sofia_receive_message() Sending media re-direct:
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 127.0.0.1
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10016 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] sofia_glue.c:880 sofia_glue_tech_proxy_remote_addr() Remote address:port [10.0.0.2:59082] has not changed.
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1005 sofia_glue_tech_patch_sdp() sofia/internal/1000@10.0.0.2 Patched SDP
---
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 127.0.0.1
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10016 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

+++
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 127.0.0.1
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 27202 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [calling]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [ready]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:880 sofia_glue_tech_proxy_remote_addr() Remote address:port [10.0.0.2:59082] has not changed.
2008-12-16 01:45:36 [DEBUG] sofia.c:2055 sofia_handle_sip_r_invite() Passing 200 OK to other leg
2008-12-16 01:45:36 [DEBUG] mod_sofia.c:1099 sofia_receive_message() Responding with 200 [OK]
2008-12-16 01:45:36 [DEBUG] sofia_glue.c:1005 sofia_glue_tech_patch_sdp() sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 Patched SDP
---
v=0
o=- 9 3 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 59082 RTP/AVP 0 101
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
a=sendrecv

+++
v=0
o=- 9 3 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 27200 RTP/AVP 0 101
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
a=sendrecv

2008-12-16 01:45:36 [DEBUG] sofia_glue.c:892 sofia_glue_tech_proxy_remote_addr() AUDIO RTP CHANGING DEST TO: [10.0.0.2:10016]
2008-12-16 01:45:36 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [ready]
2008-12-16 01:45:36 [DEBUG] sofia.c:2273 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 9 3 IN IP4 10.0.0.2
s=CounterPath X-Lite 3.0
c=IN IP4 10.0.0.2
t=0 0
m=audio 59082 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [completed]
2008-12-16 01:45:36 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [ready]
2008-12-16 01:46:20 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/1000@10.0.0.2 entering state [terminated]
2008-12-16 01:46:20 [NOTICE] sofia.c:2765 sofia_handle_sip_i_state() Hangup sofia/internal/1000@10.0.0.2 [CS_EXECUTE] [NORMAL_CLEARING]
2008-12-16 01:46:20 [DEBUG] switch_channel.c:1449 switch_channel_perform_hangup() Send signal sofia/internal/1000@10.0.0.2 [KILL]
2008-12-16 01:46:20 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/1000@10.0.0.2 [BREAK]
2008-12-16 01:46:30 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [received]
2008-12-16 01:46:30 [DEBUG] sofia.c:2273 sofia_handle_sip_i_state() Remote SDP:
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 10.0.0.2
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10012 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:46:30 [DEBUG] sofia.c:2564 sofia_handle_sip_i_state() Passing SDP to other leg.
v=0
o=voxeo.8.0.235.1 0 0 IN IP4 10.0.0.2
s=voxeo
c=IN IP4 10.0.0.2
t=0 0
m=audio 10012 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30

2008-12-16 01:46:30 [DEBUG] sofia.c:2578 sofia_handle_sip_i_state() Other leg is not available
2008-12-16 01:46:30 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [ready]
2008-12-16 01:46:40 [DEBUG] sofia.c:2269 sofia_handle_sip_i_state() Channel sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 entering state [terminated]
2008-12-16 01:46:40 [NOTICE] sofia.c:2765 sofia_handle_sip_i_state() Hangup sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2008-12-16 01:46:40 [DEBUG] switch_channel.c:1449 switch_channel_perform_hangup() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [KILL]
2008-12-16 01:46:40 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Send signal sofia/internal/sip:Doctorsoffice@127.0.0.1:5068 [BREAK]
