FreeSwitch and Exchange 2007
Hello everyone, I am trying to set a test environment with FS and Exchange 2007. Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work. According external source: "MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The 'From' field's address to be in the format '<sip:DN@IP:Port>'; otherwise, MS Exchange drops the call." I don't know if this is the only problem. However, I see exactly this behavior: "PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established." After "302 (Moved Temporarily", FreeSwitch bombs and closes without any record in the log. Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002 Thanks in advance. Drago
After days of running around clueless, I have no other option but to ask the community for help one last time. Here is what happens: 1. FS sends INVITE 2. Exchange answers with "302 Moved Temporarily" 3. FS bombs and closes Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 INVITE Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> Contact Binding: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 236 P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3> Message Body Status-Line: SIP/2.0 100 Trying Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTENT-LENGTH: 0 Status-Line: SIP/2.0 302 Moved Temporarily Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp> Contact Binding: <sip:4783874764@10.0.0.71:5065;transport=tcp> CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 ACK Content-Length: 0 Here is the FS log beginning the the processing of the call: 2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937-b321c0d87414] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/external/4782512197@209.249.3.59 entering state [received][100] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP: v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_NEW 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59) State NEW 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_INIT 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING 2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->unloop] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->outside_call] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call] Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true) Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->call_debug] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never Dialplan: sofia/external/4782512197@209.249.3.59 Action info() Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->public_extensions] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->Local_UM] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59) State Change CS_ROUTING -> CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59) State EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true) 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true] EXECUTE sofia/external/4782512197@209.249.3.59 info() 2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-State-Number: [4] Channel-Name: [sofia/external/4782512197@209.249.3.59] Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Call-Direction: [inbound] Presence-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: [4782512197] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [MILLEDGEVL GA] Caller-Caller-ID-Number: [4782512197] Caller-Network-Addr: [209.249.3.59] Caller-Destination-Number: [4783874190] Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1245613758636018] Caller-Channel-Created-Time: [1245613758636018] 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: [209.249.3.59] variable_sip_received_port: [5060] variable_sip_via_protocol: [udp] variable_sip_from_user: [4782512197] variable_sip_from_uri: [4782512197@209.249.3.59] variable_sip_from_host: [209.249.3.59] variable_sip_from_user_stripped: [4782512197] variable_sip_from_tag: [3454602382-411732] variable_sofia_profile_name: [external] variable_sip_cid_type: [pid] variable_sip_req_user: [gw+Broadvox] variable_sip_req_port: [5080] variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080] variable_sip_req_host: [71.29.0.61] variable_sip_to_user: [4783874764] variable_sip_to_port: [5060] variable_sip_to_uri: [4783874764@209.249.3.56:5060] variable_sip_to_host: [209.249.3.56] variable_sip_contact_user: [4782512197] variable_sip_contact_port: [5060] variable_sip_contact_uri: [4782512197@209.249.3.59:5060] variable_sip_contact_host: [209.249.3.59] variable_channel_name: [sofia/external/4782512197@209.249.3.59] variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net] variable_sip_via_host: [209.249.3.59] variable_sip_via_port: [5060] variable_max_forwards: [69] variable_sip_call_info: [<sip:209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"] variable_sip_gateway: [Broadvox] variable_switch_r_sdp: [v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ] variable_remote_media_ip: [209.249.3.60] variable_remote_media_port: [36292] variable_read_codec: [PCMU] variable_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_endpoint_disposition: [RECEIVED] variable_outside_call: [true] variable_current_application: [info] EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA] 2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858] 2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/4783874764) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/4783874764 SOFIA INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/4783874764) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/4783874764 SOFIA ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA 2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/internal/4783874764 entering state [calling][0] Will trade my first born for little help J Drago From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007 Hello everyone, I am trying to set a test environment with FS and Exchange 2007. Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work. According external source: "MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The 'From' field's address to be in the format '<sip:DN@IP:Port>'; otherwise, MS Exchange drops the call." I don't know if this is the only problem. However, I see exactly this behavior: "PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established." After "302 (Moved Temporarily", FreeSwitch bombs and closes without any record in the log. Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002 Thanks in advance. Drago
If this is still the case with current svn trunk, please get a backtrace and post it to http://jira.freeswitch.org On Jun 21, 2009, at 3:51 PM, "Drago Totev" <drago@windstream.net> wrote:
After days of running around clueless, I have no other option but to ask the community for help one last time…
Here is what happens:
1. FS sends INVITE
2. Exchange answers with “302 Moved Temporarily”
3. FS bombs and closes
Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/ 2.0
Message Header
Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF
Max-Forwards: 68
From: "MILLEDGEVL GA" <sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m
SIP Display info: "MILLEDGEVL GA"
SIP from address: sip:4782512197@10.8.4.3
SIP tag: Qr4j0XX18XD1m
To: <sip:4783874764@10.0.0.71>
SIP to address: sip:4783874764@10.0.0.71
Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915
CSeq: 116688296 INVITE
Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp>
Contact Binding: <sip:gw +um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH
Supported: timer, precondition, path, replaces
Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 236
P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3
Message Body
Status-Line: SIP/2.0 100 Trying
Message Header
FROM: "MILLEDGEVL GA"<sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m
SIP Display info: "MILLEDGEVL GA"
SIP from address: sip:4782512197@10.8.4.3
SIP tag: Qr4j0XX18XD1m
TO: <sip:4783874764@10.0.0.71>
SIP to address: sip:4783874764@10.0.0.71
CSEQ: 116688296 INVITE
CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915
VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF
CONTENT-LENGTH: 0
Status-Line: SIP/2.0 302 Moved Temporarily
Message Header
FROM: "MILLEDGEVL GA"<sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m
SIP Display info: "MILLEDGEVL GA"
SIP from address: sip:4782512197@10.8.4.3
SIP tag: Qr4j0XX18XD1m
TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0
SIP to address: sip:4783874764@10.0.0.71
SIP tag: 27df6afe0
CSEQ: 116688296 INVITE
CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915
VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF
CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp>
Contact Binding: <sip: 4783874764@10.0.0.71:5065;transport=tcp>
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0
Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0
Message Header
Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF
Max-Forwards: 68
From: "MILLEDGEVL GA" <sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m
SIP Display info: "MILLEDGEVL GA"
SIP from address: sip:4782512197@10.8.4.3
SIP tag: Qr4j0XX18XD1m
To: <sip:4783874764@10.0.0.71>;tag=27df6afe0
SIP to address: sip:4783874764@10.0.0.71
SIP tag: 27df6afe0
Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915
CSeq: 116688296 ACK
Content-Length: 0
Here is the FS log beginning the the processing of the call:
2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937- b321c0d87414]
2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/ external/4782512197@209.249.3.59 entering state [received][100]
2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP:
v=0
o=NXT02 19785 8060 IN IP4 209.249.3.59
s=sip call
c=IN IP4 209.249.3.60
t=0 0
m=audio 36292 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20]
2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/ external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples
2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101
2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_NEW
2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59) State NEW
2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59 ) State Change CS_NEW -> CS_INIT
2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK]
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_INIT
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT
2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT
2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59 ) State Change CS_INIT -> CS_ROUTING
2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK]
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT going to sleep
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_ROUTING
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING
2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING
2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public
Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
unloop] continue=false
Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
outside_call] continue=true
Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call]
Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true)
Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
call_debug] continue=true
Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never
Dialplan: sofia/external/4782512197@209.249.3.59 Action info()
Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
public_extensions] continue=false
Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9]) $/ break=on-false
Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
Local_UM] continue=false
Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on- false
Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/ 4783874764)
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59) State Change CS_ROUTING -> CS_EXECUTE
2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK]
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING going to sleep
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_EXECUTE
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59) State EXECUTE
2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE
2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE
EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true)
2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true]
EXECUTE sofia/external/4782512197@209.249.3.59 info()
2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/external/4782512197@209.249.3.59]
Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414]
Call-Direction: [inbound]
Presence-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: [4782512197]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [MILLEDGEVL GA]
Caller-Caller-ID-Number: [4782512197]
Caller-Network-Addr: [209.249.3.59]
Caller-Destination-Number: [4783874190]
Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414]
Caller-Source: [mod_sofia]
Caller-Context: [public]
Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1245613758636018]
Caller-Channel-Created-Time: [1245613758636018]
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: [209.249.3.59]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_from_user: [4782512197]
variable_sip_from_uri: [4782512197@209.249.3.59]
variable_sip_from_host: [209.249.3.59]
variable_sip_from_user_stripped: [4782512197]
variable_sip_from_tag: [3454602382-411732]
variable_sofia_profile_name: [external]
variable_sip_cid_type: [pid]
variable_sip_req_user: [gw+Broadvox]
variable_sip_req_port: [5080]
variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080]
variable_sip_req_host: [71.29.0.61]
variable_sip_to_user: [4783874764]
variable_sip_to_port: [5060]
variable_sip_to_uri: [4783874764@209.249.3.56:5060]
variable_sip_to_host: [209.249.3.56]
variable_sip_contact_user: [4782512197]
variable_sip_contact_port: [5060]
variable_sip_contact_uri: [4782512197@209.249.3.59:5060]
variable_sip_contact_host: [209.249.3.59]
variable_channel_name: [sofia/external/4782512197@209.249.3.59]
variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net]
variable_sip_via_host: [209.249.3.59]
variable_sip_via_port: [5060]
variable_max_forwards: [69]
variable_sip_call_info: [<sip: 209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"]
variable_sip_gateway: [Broadvox]
variable_switch_r_sdp: [v=0
o=NXT02 19785 8060 IN IP4 209.249.3.59
s=sip call
c=IN IP4 209.249.3.60
t=0 0
m=audio 36292 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
]
variable_remote_media_ip: [209.249.3.60]
variable_remote_media_port: [36292]
variable_read_codec: [PCMU]
variable_read_rate: [8000]
variable_write_codec: [PCMU]
variable_write_rate: [8000]
variable_endpoint_disposition: [RECEIVED]
variable_outside_call: [true]
variable_current_application: [info]
EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/ 4783874764)
2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA]
2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858]
2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/ 4783874764) State Change CS_NEW -> CS_INIT
2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK]
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT
2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/4783874764 SOFIA INIT
2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/ 4783874764) State Change CS_INIT -> CS_ROUTING
2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK]
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING
2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/4783874764 SOFIA ROUTING
2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/ internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK]
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA
2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA
2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/ internal/4783874764 entering state [calling][0]
Will trade my first born for little help J
Drago
From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org ] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007
Hello everyone,
I am trying to set a test environment with FS and Exchange 2007.
Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work.
According external source:
“MS Exchange does not understand 'From' fields with domain name in t he address (example: field containing <sip:100@3CXPhoneSystem> addre ss).The ‘From’ field’s address to be in the format ‘<sip:DN@IP:Port>’; otherwise, MS Exchange drops the call.”
I don’t know if this is the only problem… However, I see exactly thi s behavior:
“PBX initiates call to MS Exchange by sending a SIP INVITE message t o the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Tempora rily) response to PBX asking to repeat INVITE to a different port (5 065 for example). After PBX repeats the INVITE sending, the call is established.”
After “302 (Moved Temporarily”, FreeSwitch bombs and closes without any record in the log.
Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002
Thanks in advance.
Drago
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Wiki does not have instruction how to do so on Windows (I should have mention this in the beginning – sorry about that). Can I do it anyway? From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Michael Jerris Sent: Sunday, June 21, 2009 4:31 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] FreeSwitch and Exchange 2007 If this is still the case with current svn trunk, please get a backtrace and post it to http://jira.freeswitch.org On Jun 21, 2009, at 3:51 PM, "Drago Totev" <drago@windstream.net> wrote: After days of running around clueless, I have no other option but to ask the community for help one last time… Here is what happens: 1. FS sends INVITE 2. Exchange answers with “302 Moved Temporarily” 3. FS bombs and closes Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 INVITE Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> Contact Binding: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 236 P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3> Message Body Status-Line: SIP/2.0 100 Trying Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTENT-LENGTH: 0 Status-Line: SIP/2.0 302 Moved Temporarily Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp> Contact Binding: <sip:4783874764@10.0.0.71:5065;transport=tcp> CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 ACK Content-Length: 0 Here is the FS log beginning the the processing of the call: 2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937-b321c0d87414] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/external/4782512197@209.249.3.59 entering state [received][100] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP: v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_NEW 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59) State NEW 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_INIT 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING 2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->unloop] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->outside_call] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call] Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true) Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->call_debug] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never Dialplan: sofia/external/4782512197@209.249.3.59 Action info() Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->public_extensions] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->Local_UM] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59) State Change CS_ROUTING -> CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59) State EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true) 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true] EXECUTE sofia/external/4782512197@209.249.3.59 info() 2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-State-Number: [4] Channel-Name: [sofia/external/4782512197@209.249.3.59] Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Call-Direction: [inbound] Presence-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: [4782512197] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [MILLEDGEVL GA] Caller-Caller-ID-Number: [4782512197] Caller-Network-Addr: [209.249.3.59] Caller-Destination-Number: [4783874190] Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1245613758636018] Caller-Channel-Created-Time: [1245613758636018] 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: [209.249.3.59] variable_sip_received_port: [5060] variable_sip_via_protocol: [udp] variable_sip_from_user: [4782512197] variable_sip_from_uri: [4782512197@209.249.3.59] variable_sip_from_host: [209.249.3.59] variable_sip_from_user_stripped: [4782512197] variable_sip_from_tag: [3454602382-411732] variable_sofia_profile_name: [external] variable_sip_cid_type: [pid] variable_sip_req_user: [gw+Broadvox] variable_sip_req_port: [5080] variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080] variable_sip_req_host: [71.29.0.61] variable_sip_to_user: [4783874764] variable_sip_to_port: [5060] variable_sip_to_uri: [4783874764@209.249.3.56:5060] variable_sip_to_host: [209.249.3.56] variable_sip_contact_user: [4782512197] variable_sip_contact_port: [5060] variable_sip_contact_uri: [4782512197@209.249.3.59:5060] variable_sip_contact_host: [209.249.3.59] variable_channel_name: [sofia/external/4782512197@209.249.3.59] variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net] variable_sip_via_host: [209.249.3.59] variable_sip_via_port: [5060] variable_max_forwards: [69] variable_sip_call_info: [<sip:209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"] variable_sip_gateway: [Broadvox] variable_switch_r_sdp: [v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ] variable_remote_media_ip: [209.249.3.60] variable_remote_media_port: [36292] variable_read_codec: [PCMU] variable_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_endpoint_disposition: [RECEIVED] variable_outside_call: [true] variable_current_application: [info] EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA] 2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858] 2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/4783874764) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/4783874764 SOFIA INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/4783874764) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/4783874764 SOFIA ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA 2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/internal/4783874764 entering state [calling][0] Will trade my first born for little help J Drago From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007 Hello everyone, I am trying to set a test environment with FS and Exchange 2007. Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work. According external source: “MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The ‘From’ field’s address to be in the format ‘<sip:DN@IP:Port>’; otherwise, MS Exchange drops the call.” I don’t know if this is the only problem… However, I see exactly this behavior: “PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established.” After “302 (Moved Temporarily”, FreeSwitch bombs and closes without any record in the log. Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002 Thanks in advance. Drago _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
The Windows Application Log shows this, however: 1331177817 1 APPCRASH Not available 0 FreeSwitch.exe 0.0.0.0 4a316e86 MSVCR90.dll 9.0.30729.4918 49d43da7 c0000005 0003b590 From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Michael Jerris Sent: Sunday, June 21, 2009 4:31 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] FreeSwitch and Exchange 2007 If this is still the case with current svn trunk, please get a backtrace and post it to http://jira.freeswitch.org On Jun 21, 2009, at 3:51 PM, "Drago Totev" <drago@windstream.net> wrote: After days of running around clueless, I have no other option but to ask the community for help one last time… Here is what happens: 1. FS sends INVITE 2. Exchange answers with “302 Moved Temporarily” 3. FS bombs and closes Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 INVITE Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> Contact Binding: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 236 P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3> Message Body Status-Line: SIP/2.0 100 Trying Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTENT-LENGTH: 0 Status-Line: SIP/2.0 302 Moved Temporarily Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp> Contact Binding: <sip:4783874764@10.0.0.71:5065;transport=tcp> CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 ACK Content-Length: 0 Here is the FS log beginning the the processing of the call: 2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937-b321c0d87414] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/external/4782512197@209.249.3.59 entering state [received][100] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP: v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_NEW 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59) State NEW 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_INIT 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING 2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->unloop] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->outside_call] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call] Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true) Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->call_debug] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never Dialplan: sofia/external/4782512197@209.249.3.59 Action info() Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->public_extensions] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->Local_UM] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59) State Change CS_ROUTING -> CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59) State EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true) 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true] EXECUTE sofia/external/4782512197@209.249.3.59 info() 2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-State-Number: [4] Channel-Name: [sofia/external/4782512197@209.249.3.59] Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Call-Direction: [inbound] Presence-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: [4782512197] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [MILLEDGEVL GA] Caller-Caller-ID-Number: [4782512197] Caller-Network-Addr: [209.249.3.59] Caller-Destination-Number: [4783874190] Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1245613758636018] Caller-Channel-Created-Time: [1245613758636018] 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: [209.249.3.59] variable_sip_received_port: [5060] variable_sip_via_protocol: [udp] variable_sip_from_user: [4782512197] variable_sip_from_uri: [4782512197@209.249.3.59] variable_sip_from_host: [209.249.3.59] variable_sip_from_user_stripped: [4782512197] variable_sip_from_tag: [3454602382-411732] variable_sofia_profile_name: [external] variable_sip_cid_type: [pid] variable_sip_req_user: [gw+Broadvox] variable_sip_req_port: [5080] variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080] variable_sip_req_host: [71.29.0.61] variable_sip_to_user: [4783874764] variable_sip_to_port: [5060] variable_sip_to_uri: [4783874764@209.249.3.56:5060] variable_sip_to_host: [209.249.3.56] variable_sip_contact_user: [4782512197] variable_sip_contact_port: [5060] variable_sip_contact_uri: [4782512197@209.249.3.59:5060] variable_sip_contact_host: [209.249.3.59] variable_channel_name: [sofia/external/4782512197@209.249.3.59] variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net] variable_sip_via_host: [209.249.3.59] variable_sip_via_port: [5060] variable_max_forwards: [69] variable_sip_call_info: [<sip:209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"] variable_sip_gateway: [Broadvox] variable_switch_r_sdp: [v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ] variable_remote_media_ip: [209.249.3.60] variable_remote_media_port: [36292] variable_read_codec: [PCMU] variable_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_endpoint_disposition: [RECEIVED] variable_outside_call: [true] variable_current_application: [info] EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA] 2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858] 2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/4783874764) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/4783874764 SOFIA INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/4783874764) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/4783874764 SOFIA ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA 2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/internal/4783874764 entering state [calling][0] Will trade my first born for little help J Drago From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007 Hello everyone, I am trying to set a test environment with FS and Exchange 2007. Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work. According external source: “MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The ‘From’ field’s address to be in the format ‘<sip:DN@IP:Port>’; otherwise, MS Exchange drops the call.” I don’t know if this is the only problem… However, I see exactly this behavior: “PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established.” After “302 (Moved Temporarily”, FreeSwitch bombs and closes without any record in the log. Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002 Thanks in advance. Drago _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Michael, It is definitely a problem in this build (13754M) (Windows) I found build from March and it does not brakes (still no joy, but not sure for now if the exchange side is configured properly). Again, I would submit bug report is you can point me to instructions how to do collect backtrace on Windows OS. Drago From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Michael Jerris Sent: Sunday, June 21, 2009 4:31 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] FreeSwitch and Exchange 2007 If this is still the case with current svn trunk, please get a backtrace and post it to http://jira.freeswitch.org On Jun 21, 2009, at 3:51 PM, "Drago Totev" <drago@windstream.net> wrote: After days of running around clueless, I have no other option but to ask the community for help one last time… Here is what happens: 1. FS sends INVITE 2. Exchange answers with “302 Moved Temporarily” 3. FS bombs and closes Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 INVITE Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> Contact Binding: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 236 P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3> Message Body Status-Line: SIP/2.0 100 Trying Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTENT-LENGTH: 0 Status-Line: SIP/2.0 302 Moved Temporarily Message Header FROM: "MILLEDGEVL GA"<sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp> Contact Binding: <sip:4783874764@10.0.0.71:5065;transport=tcp> CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 ACK Content-Length: 0 Here is the FS log beginning the the processing of the call: 2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937-b321c0d87414] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/external/4782512197@209.249.3.59 entering state [received][100] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP: v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_NEW 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59) State NEW 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_INIT 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59) State INIT going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING 2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->unloop] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->outside_call] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call] Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true) Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->call_debug] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never Dialplan: sofia/external/4782512197@209.249.3.59 Action info() Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->public_extensions] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public->Local_UM] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59) State Change CS_ROUTING -> CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59) State ROUTING going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59) Running State Change CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59) State EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true) 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true] EXECUTE sofia/external/4782512197@209.249.3.59 info() 2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-State-Number: [4] Channel-Name: [sofia/external/4782512197@209.249.3.59] Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Call-Direction: [inbound] Presence-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: [4782512197] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [MILLEDGEVL GA] Caller-Caller-ID-Number: [4782512197] Caller-Network-Addr: [209.249.3.59] Caller-Destination-Number: [4783874190] Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1245613758636018] Caller-Channel-Created-Time: [1245613758636018] 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: [209.249.3.59] variable_sip_received_port: [5060] variable_sip_via_protocol: [udp] variable_sip_from_user: [4782512197] variable_sip_from_uri: [4782512197@209.249.3.59] variable_sip_from_host: [209.249.3.59] variable_sip_from_user_stripped: [4782512197] variable_sip_from_tag: [3454602382-411732] variable_sofia_profile_name: [external] variable_sip_cid_type: [pid] variable_sip_req_user: [gw+Broadvox] variable_sip_req_port: [5080] variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080] variable_sip_req_host: [71.29.0.61] variable_sip_to_user: [4783874764] variable_sip_to_port: [5060] variable_sip_to_uri: [4783874764@209.249.3.56:5060] variable_sip_to_host: [209.249.3.56] variable_sip_contact_user: [4782512197] variable_sip_contact_port: [5060] variable_sip_contact_uri: [4782512197@209.249.3.59:5060] variable_sip_contact_host: [209.249.3.59] variable_channel_name: [sofia/external/4782512197@209.249.3.59] variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net] variable_sip_via_host: [209.249.3.59] variable_sip_via_port: [5060] variable_max_forwards: [69] variable_sip_call_info: [<sip:209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"] variable_sip_gateway: [Broadvox] variable_switch_r_sdp: [v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ] variable_remote_media_ip: [209.249.3.60] variable_remote_media_port: [36292] variable_read_codec: [PCMU] variable_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_endpoint_disposition: [RECEIVED] variable_outside_call: [true] variable_current_application: [info] EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/4783874764) 2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA] 2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858] 2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/4783874764) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/4783874764 SOFIA INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/4783874764) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/4783874764 SOFIA ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA 2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/internal/4783874764 entering state [calling][0] Will trade my first born for little help J Drago From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007 Hello everyone, I am trying to set a test environment with FS and Exchange 2007. Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work. According external source: “MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The ‘From’ field’s address to be in the format ‘<sip:DN@IP:Port>’; otherwise, MS Exchange drops the call.” I don’t know if this is the only problem… However, I see exactly this behavior: “PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established.” After “302 (Moved Temporarily”, FreeSwitch bombs and closes without any record in the log. Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002 Thanks in advance. Drago _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
if you run from the visual studio ide, there is a windows that shows the stack trace. Mike On Jun 22, 2009, at 4:33 PM, Drago Totev wrote:
Michael,
It is definitely a problem in this build (13754M) (Windows)
I found build from March and it does not brakes (still no joy, but not sure for now if the exchange side is configured properly).
Again, I would submit bug report is you can point me to instructions how to do collect backtrace on Windows OS.
Drago
From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org ] On Behalf Of Michael Jerris Sent: Sunday, June 21, 2009 4:31 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] FreeSwitch and Exchange 2007
If this is still the case with current svn trunk, please get a backtrace and post it to http://jira.freeswitch.org
On Jun 21, 2009, at 3:51 PM, "Drago Totev" <drago@windstream.net> wrote: After days of running around clueless, I have no other option but to ask the community for help one last time…
Here is what happens:
1. FS sends INVITE
2. Exchange answers with “302 Moved Temporarily”
3. FS bombs and closes
Request-Line: INVITE sip:4783874764@10.0.0.71;transport=tcp SIP/ 2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 INVITE Contact: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp> Contact Binding: <sip:gw+um.gmc.cc.ga.us@10.8.4.3:5060;transport=tcp
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-13754M Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: timer, precondition, path, replaces Allow-Events: talk, presence, dialog, call-info, sla, include-session-description, presence.winfo, message-summary, refer Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 236 P-Asserted-Identity: "MILLEDGEVL GA" <sip:4782512197@10.8.4.3
Message Body
Status-Line: SIP/2.0 100 Trying Message Header FROM: "MILLEDGEVL GA"<sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71> SIP to address: sip:4783874764@10.0.0.71 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTENT-LENGTH: 0
Status-Line: SIP/2.0 302 Moved Temporarily Message Header FROM: "MILLEDGEVL GA"<sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m TO: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 CSEQ: 116688296 INVITE CALL-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 VIA: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF CONTACT: <sip:4783874764@10.0.0.71:5065;transport=tcp> Contact Binding: <sip:4783874764@10.0.0.71:5065;transport=tcp
CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0
Request-Line: ACK sip:4783874764@10.0.0.71;transport=tcp SIP/2.0 Message Header Via: SIP/2.0/TCP 10.8.4.3;branch=z9hG4bKQcm1vS26UU3KF Max-Forwards: 68 From: "MILLEDGEVL GA" <sip: 4782512197@10.8.4.3>;tag=Qr4j0XX18XD1m SIP Display info: "MILLEDGEVL GA" SIP from address: sip:4782512197@10.8.4.3 SIP tag: Qr4j0XX18XD1m To: <sip:4783874764@10.0.0.71>;tag=27df6afe0 SIP to address: sip:4783874764@10.0.0.71 SIP tag: 27df6afe0 Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915 CSeq: 116688296 ACK Content-Length: 0
Here is the FS log beginning the the processing of the call:
2009-06-21 15:49:18.636018 [NOTICE] switch_channel.c:602 New Channel sofia/external/4782512197@209.249.3.59 [637f8a72-8034-254f-9937-b321c0d87414] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/external/4782512197@209.249.3.59 entering state [received][100] 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3217 Remote SDP: v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15
2009-06-21 15:49:18.636018 [DEBUG] sofia_glue.c:3079 Audio Codec Compare [PCMU:0:8000:0]/[PCMU:0:8000:20] 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:2037 Set Codec sofia/external/4782512197@209.249.3.59 PCMU/8000 20 ms 160 samples 2009-06-21 15:49:18.637018 [DEBUG] sofia_glue.c:3039 Set 2833 dtmf payload to 101 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59 ) Running State Change CS_NEW 2009-06-21 15:49:18.637018 [DEBUG] switch_core_state_machine.c:403 (sofia/external/4782512197@209.249.3.59 ) State NEW 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197@209.249.3.59 ) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.637018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59 ) Running State Change CS_INIT 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59 ) State INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197@209.249.3.59 SOFIA INIT 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197@209.249.3.59 ) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480 (sofia/external/4782512197@209.249.3.59 ) State INIT going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59 ) Running State Change CS_ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59 ) State ROUTING 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197@209.249.3.59 SOFIA ROUTING 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78 sofia/external/4782512197@209.249.3.59 Standard ROUTING 2009-06-21 15:49:18.647018 [INFO] mod_dialplan_xml.c:252 Processing MILLEDGEVL GA->4783874190 in context public Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public-
unloop] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public- outside_call] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Absolute Condition [outside_call] Dialplan: sofia/external/4782512197@209.249.3.59 Action set(outside_call=true) Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public- call_debug] continue=true Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never Dialplan: sofia/external/4782512197@209.249.3.59 Action info() Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public- public_extensions] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (FAIL) [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9]) $/ break=on-false Dialplan: sofia/external/4782512197@209.249.3.59 parsing [public- Local_UM] continue=false Dialplan: sofia/external/4782512197@209.249.3.59 Regex (PASS) [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on- false Dialplan: sofia/external/4782512197@209.249.3.59 Action bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/ 4783874764) 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:114 (sofia/external/4782512197@209.249.3.59 ) State Change CS_ROUTING -> CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_session.c:933 Send signal sofia/external/4782512197@209.249.3.59 [BREAK] 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483 (sofia/external/4782512197@209.249.3.59 ) State ROUTING going to sleep 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397 (sofia/external/4782512197@209.249.3.59 ) Running State Change CS_EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:490 (sofia/external/4782512197@209.249.3.59 ) State EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197@209.249.3.59 SOFIA EXECUTE 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151 sofia/external/4782512197@209.249.3.59 Standard EXECUTE EXECUTE sofia/external/4782512197@209.249.3.59 set(outside_call=true) 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197@209.249.3.59 SET [outside_call]=[true] EXECUTE sofia/external/4782512197@209.249.3.59 info() 2009-06-21 15:49:18.648018 [INFO] mod_dptools.c:946 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-State-Number: [4] Channel-Name: [sofia/external/4782512197@209.249.3.59] Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Call-Direction: [inbound] Presence-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: [4782512197] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [MILLEDGEVL GA] Caller-Caller-ID-Number: [4782512197] Caller-Network-Addr: [209.249.3.59] Caller-Destination-Number: [4783874190] Caller-Unique-ID: [637f8a72-8034-254f-9937-b321c0d87414] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/4782512197@209.249.3.59] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1245613758636018] Caller-Channel-Created-Time: [1245613758636018] 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: [209.249.3.59] variable_sip_received_port: [5060] variable_sip_via_protocol: [udp] variable_sip_from_user: [4782512197] variable_sip_from_uri: [4782512197@209.249.3.59] variable_sip_from_host: [209.249.3.59] variable_sip_from_user_stripped: [4782512197] variable_sip_from_tag: [3454602382-411732] variable_sofia_profile_name: [external] variable_sip_cid_type: [pid] variable_sip_req_user: [gw+Broadvox] variable_sip_req_port: [5080] variable_sip_req_uri: [gw+Broadvox@71.29.0.61:5080] variable_sip_req_host: [71.29.0.61] variable_sip_to_user: [4783874764] variable_sip_to_port: [5060] variable_sip_to_uri: [4783874764@209.249.3.56:5060] variable_sip_to_host: [209.249.3.56] variable_sip_contact_user: [4782512197] variable_sip_contact_port: [5060] variable_sip_contact_uri: [4782512197@209.249.3.59:5060] variable_sip_contact_host: [209.249.3.59] variable_channel_name: [sofia/external/4782512197@209.249.3.59] variable_sip_call_id: [6891536-3454602382-411724@NXT02.broadvox.net] variable_sip_via_host: [209.249.3.59] variable_sip_via_port: [5060] variable_max_forwards: [69] variable_sip_call_info: [<sip: 209.249.3.59>;method="NOTIFY;Event=telephone-event;Duration=1000"] variable_sip_gateway: [Broadvox] variable_switch_r_sdp: [v=0 o=NXT02 19785 8060 IN IP4 209.249.3.59 s=sip call c=IN IP4 209.249.3.60 t=0 0 m=audio 36292 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ] variable_remote_media_ip: [209.249.3.60] variable_remote_media_port: [36292] variable_read_codec: [PCMU] variable_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_endpoint_disposition: [RECEIVED] variable_outside_call: [true] variable_current_application: [info]
EXECUTE sofia/external/4782512197@209.249.3.59 bridge({absolute_codec_string=PCMA}sofia/gateway/um.gmc.cc.ga.us/ 4783874764) 2009-06-21 15:49:18.648018 [DEBUG] switch_ivr_originate.c:1017 variable string 0 = [absolute_codec_string=PCMA] 2009-06-21 15:49:18.648018 [NOTICE] switch_channel.c:602 New Channel sofia/internal/4783874764 [34ad0b66-9324-604e-931a-d0e6468ce858] 2009-06-21 15:49:18.648018 [DEBUG] mod_sofia.c:2737 (sofia/internal/ 4783874764) State Change CS_NEW -> CS_INIT 2009-06-21 15:49:18.648018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_INIT 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:83 sofia/internal/ 4783874764 SOFIA INIT 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:111 (sofia/internal/ 4783874764) State Change CS_INIT -> CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/4783874764) State INIT going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING 2009-06-21 15:49:18.650018 [DEBUG] mod_sofia.c:130 sofia/internal/ 4783874764 SOFIA ROUTING 2009-06-21 15:49:18.650018 [DEBUG] switch_ivr_originate.c:63 (sofia/ internal/4783874764) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/4783874764 [BREAK] 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/4783874764) State ROUTING going to sleep 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/4783874764) Running State Change CS_CONSUME_MEDIA 2009-06-21 15:49:18.650018 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/4783874764) State CONSUME_MEDIA 2009-06-21 15:49:18.651018 [DEBUG] sofia.c:3210 Channel sofia/ internal/4783874764 entering state [calling][0]
Will trade my first born for little help J
Drago
From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org ] On Behalf Of Drago Totev Sent: Sunday, June 14, 2009 7:11 PM To: freeswitch-users@lists.freeswitch.org Subject: [Freeswitch-users] FreeSwitch and Exchange 2007
Hello everyone,
I am trying to set a test environment with FS and Exchange 2007.
Followed the instructions listed here: http://wiki.freeswitch.org/wiki/Exchange_2007_UM and it does not seem to work. Thus far I use the default settings, one ATA registered and confirmed to work.
According external source:
“MS Exchange does not understand 'From' fields with domain name in the address (example: field containing <sip:100@3CXPhoneSystem> address).The ‘From’ field’s address to be in the format ‘<sip:DN@IP:Port
’; otherwise, MS Exchange drops the call.”
I don’t know if this is the only problem… However, I see exactly this behavior:
“PBX initiates call to MS Exchange by sending a SIP INVITE message to the 5060 port of MS Exchange. MS Exchange sends 302 (Moved Temporarily) response to PBX asking to repeat INVITE to a different port (5065 for example). After PBX repeats the INVITE sending, the call is established.”
After “302 (Moved Temporarily”, FreeSwitch bombs and closes without any record in the log.
Can someone help with working configuration, please? Exchange 2007 UM role Version: 08.01.0359.002
Thanks in advance.
Drago
_______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _______________________________________________ Freeswitch-users mailing list Freeswitch-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (2)
-
Drago Totev
-
Michael Jerris