[Freeswitch-users] FreeSwitch and Exchange 2007
Michael Jerris
mike at jerris.com
Tue Jun 23 09:26:30 PDT 2009
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 at lists.freeswitch.org [mailto:freeswitch-users-bounces at lists.freeswitch.org
> ] On Behalf Of Michael Jerris
> Sent: Sunday, June 21, 2009 4:31 PM
> To: freeswitch-users at 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 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
> the address (example: field containing <sip:100 at 3CXPhoneSystem>
> address).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
> 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 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
> _______________________________________________
> 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/20090623/9056a56b/attachment-0002.html
More information about the FreeSWITCH-users
mailing list