[Freeswitch-users] FreeSwitch and Exchange 2007
Michael Jerris
mike at jerris.com
Sun Jun 21 13:31:04 PDT 2009
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 at 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 at 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 at 10.8.4.3>;tag=Qr4j0XX18XD1m
>
> SIP Display info: "MILLEDGEVL GA"
>
> SIP from address: sip:4782512197 at 10.8.4.3
>
> SIP tag: Qr4j0XX18XD1m
>
> To: <sip:4783874764 at 10.0.0.71>
>
> SIP to address: sip:4783874764 at 10.0.0.71
>
> Call-ID: 4cdf31d7-d93e-122c-9f93-11adca034915
>
> CSeq: 116688296 INVITE
>
> Contact: <sip:gw+um.gmc.cc.ga.us at 10.8.4.3:5060;transport=tcp>
>
> Contact Binding: <sip:gw
> +um.gmc.cc.ga.us at 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 at 10.8.4.3
> >
>
> Message Body
>
>
>
>
>
>
>
> Status-Line: SIP/2.0 100 Trying
>
> Message Header
>
> FROM: "MILLEDGEVL GA"<sip:
> 4782512197 at 10.8.4.3>;tag=Qr4j0XX18XD1m
>
> SIP Display info: "MILLEDGEVL GA"
>
> SIP from address: sip:4782512197 at 10.8.4.3
>
> SIP tag: Qr4j0XX18XD1m
>
> TO: <sip:4783874764 at 10.0.0.71>
>
> SIP to address: sip:4783874764 at 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 at 10.8.4.3>;tag=Qr4j0XX18XD1m
>
> SIP Display info: "MILLEDGEVL GA"
>
> SIP from address: sip:4782512197 at 10.8.4.3
>
> SIP tag: Qr4j0XX18XD1m
>
> TO: <sip:4783874764 at 10.0.0.71>;tag=27df6afe0
>
> SIP to address: sip:4783874764 at 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 at 10.0.0.71:5065;transport=tcp>
>
> Contact Binding: <sip:
> 4783874764 at 10.0.0.71:5065;transport=tcp>
>
> CONTENT-LENGTH: 0
>
> SERVER: RTCC/3.0.0.0
>
>
>
>
>
> Request-Line: ACK sip:4783874764 at 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 at 10.8.4.3>;tag=Qr4j0XX18XD1m
>
> SIP Display info: "MILLEDGEVL GA"
>
> SIP from address: sip:4782512197 at 10.8.4.3
>
> SIP tag: Qr4j0XX18XD1m
>
> To: <sip:4783874764 at 10.0.0.71>;tag=27df6afe0
>
> SIP to address: sip:4783874764 at 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 at 209.249.3.59 [637f8a72-8034-254f-9937-
> b321c0d87414]
>
> 2009-06-21 15:49:18.636018 [DEBUG] sofia.c:3210 Channel sofia/
> external/4782512197 at 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 at 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 at 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 at 209.249.3.59) State NEW
>
> 2009-06-21 15:49:18.637018 [DEBUG] sofia.c:3376 (sofia/external/4782512197 at 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 at 209.249.3.59 [BREAK]
>
> 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:397
> (sofia/external/4782512197 at 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 at 209.249.3.59) State INIT
>
> 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:83 sofia/external/4782512197 at 209.249.3.59
> SOFIA INIT
>
> 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:111 (sofia/external/4782512197 at 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 at 209.249.3.59 [BREAK]
>
> 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:480
> (sofia/external/4782512197 at 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 at 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 at 209.249.3.59) State ROUTING
>
> 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:130 sofia/external/4782512197 at 209.249.3.59
> SOFIA ROUTING
>
> 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:78
> sofia/external/4782512197 at 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 at 209.249.3.59 parsing [public-
> >unloop] continue=false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Regex (PASS)
> [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Regex (FAIL)
> [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 parsing [public-
> >outside_call] continue=true
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Absolute Condition
> [outside_call]
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Action
> set(outside_call=true)
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 parsing [public-
> >call_debug] continue=true
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Regex (PASS)
> [call_debug] ${call_debug}(true) =~ /^true$/ break=never
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Action info()
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 parsing [public-
> >public_extensions] continue=false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Regex (FAIL)
> [public_extensions] destination_number(4783874190) =~ /^(10[01][0-9])
> $/ break=on-false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 parsing [public-
> >Local_UM] continue=false
>
> Dialplan: sofia/external/4782512197 at 209.249.3.59 Regex (PASS)
> [Local_UM] ${sip_to_user}(4783874764) =~ /^(4783874764)$/ break=on-
> false
>
> Dialplan: sofia/external/4782512197 at 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 at 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 at 209.249.3.59 [BREAK]
>
> 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:483
> (sofia/external/4782512197 at 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 at 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 at 209.249.3.59) State EXECUTE
>
> 2009-06-21 15:49:18.647018 [DEBUG] mod_sofia.c:173 sofia/external/4782512197 at 209.249.3.59
> SOFIA EXECUTE
>
> 2009-06-21 15:49:18.647018 [DEBUG] switch_core_state_machine.c:151
> sofia/external/4782512197 at 209.249.3.59 Standard EXECUTE
>
> EXECUTE sofia/external/4782512197 at 209.249.3.59 set(outside_call=true)
>
> 2009-06-21 15:49:18.647018 [DEBUG] mod_dptools.c:748 sofia/external/4782512197 at 209.249.3.59
> SET [outside_call]=[true]
>
> EXECUTE sofia/external/4782512197 at 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 at 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 at 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 at 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 at 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 at 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 at 209.249.3.59:5060]
>
> variable_sip_contact_host: [209.249.3.59]
>
> variable_channel_name: [sofia/external/4782512197 at 209.249.3.59]
>
> variable_sip_call_id: [6891536-3454602382-411724 at 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 at 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 at lists.freeswitch.org [mailto:freeswitch-users-bounces at lists.freeswitch.org
> ] On Behalf Of Drago Totev
> Sent: Sunday, June 14, 2009 7:11 PM
> To: freeswitch-users at 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 at 3CXPhoneSystem> addre
> ss).The ‘From’ field’s address to be in the format
> ‘<sip:DN at 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 at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20090621/85be5cc9/attachment-0002.html
More information about the FreeSWITCH-users
mailing list