Wednesday, January 26, 2011

Outbound call to PSTN network fails from Lync client connected through edge with event ID: 11 warning logged on the desktop or laptop

As with OCS 2007 R2, there are plenty of reasons why a call would fail so please be aware that this is one of the many reasons why.

Problem

You’re connected to your Lync Server 2010 server pool through the Edge server:

image

You initiate a call to the PSTN network which requires Edge server and Lync Pool to establish a connection.

The call fails and the following Event ID: 11 warning is logged on your laptop or desktop where the Lync client is installed:

image

Here are is what the description of the warning contains:

A SIP request made by Communicator failed in an unexpected manner (status code 80ef01f7). More information is contained in the following technical data:
RequestUri:   sip:+15555555555@someDomain.com;user=phone
From:         sip:tluk@someDomain.com;tag=62d2e6902c
To:           sip:+15555555555@someDomain.com;user=phone;tag=0915A1DBDA1035365414B9264D44845B
Call-ID:      dcc19df7992d4b639702a80b4e31636b
Content-type: multipart/alternative;boundary="----=_NextPart_000_024F_01CBBD97.5707C730";call-type=audiovideo

------=_NextPart_000_024F_01CBBD97.5707C730
Content-Type: application/sdp
Content-Transfer-Encoding: 7bit
Content-ID: <77c25095274b4382adf7cb40c6c851d0@someDomain.com>
Content-Disposition: session; handling=optional; ms-proxy-2007fallback

v=0
o=- 0 0 IN IP4 192.168.0.101
s=session
c=IN IP4 192.168.0.101
b=CT:53980
t=0 0
m=audio 11328 RTP/SAVP 114 9 112 111 0 8 116 115 4 97 13 118 101
a=candidate:7n/37im6mXRfZGCpjsJEJKLakDnDyuMyP4eF+AamnNo 1 geFlE+K5uZoitoh8DIKMmw UDP 0.830 172.20.13.247 31600
a=candidate:7n/37im6mXRfZGCpjsJEJKLakDnDyuMyP4eF+AamnNo 2 geFlE+K5uZoitoh8DIKMmw UDP 0.830 172.20.13.247 31601
a=candidate:aiU9vRUyTw9cSKSPPCfM0UZS2ezDhnbQmMpBUvE/iKc 1 fWXrzjCPAe4lof3LM6zbXA UDP 0.840 192.168.0.101 11328
a=candidate:aiU9vRUyTw9cSKSPPCfM0UZS2ezDhnbQmMpBUvE/iKc 2 fWXrzjCPAe4lof3LM6zbXA UDP 0.840 192.168.0.101 11329
a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:NZUPXQBH7VwA0uuuHrlKbIXQP5l5KryO6RzqWgIH|2^31|1:1
a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:lzD/UHd0AVadfXle+0SWCbYj7Hrc93JurB87nLJr|2^31|1:1
a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:oliHsG5m4qlK0Gk4ww6+U7to0Vkj77HHgia8SCAM|2^31
a=maxptime:200
a=rtpmap:114 x-msrta/16000
a=fmtp:114 bitrate=29000
a=rtpmap:9 G722/8000
a=rtpmap:112 G7221/16000
a=fmtp:112 bitrate=24000
a=rtpmap:111 SIREN/16000
a=fmtp:111 bitrate=16000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:116 AAL2-G726-32/8000
a=rtpmap:115 x-msrta/8000
a=fmtp:115 bitrate=11800
a=rtpmap:4 G723/8000
a=rtpmap:97 RED/8000
a=rtpmap:13 CN/8000
a=rtpmap:118 CN/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=encryption:required

------=_NextPart_000_024F_01CBBD97.5707C730
Content-Type: application/sdp
Content-Transfer-Encoding: 7bit
Content-ID: <a061ef8d0bb84a65bafcf31efcafde08@someDomain.com>
Content-Disposition: session; handling=optional

v=0
o=- 0 0 IN IP4 192.168.0.101
s=session
c=IN IP4 192.168.0.101
b=CT:53980
t=0 0
m=audio 8332 RTP/SAVP 114 9 112 111 0 8 116 115 4 97 13 118 101
a=ice-ufrag:L5ut
a=ice-pwd:TKzf9ZbNGtObJgAxQ7oiX1Mn
a=candidate:1 1 UDP 2130706431 192.168.0.101 8332 typ host
a=candidate:1 2 UDP 2130705918 192.168.0.101 8333 typ host
a=candidate:2 1 UDP 2130705919 172.20.13.247 26972 typ host
a=candidate:2 2 UDP 2130705406 172.20.13.247 26973 typ host
a=candidate:3 1 TCP-ACT 1684798463 192.168.0.101 8332 typ srflx raddr 192.168.0.101 rport 8332
a=candidate:3 2 TCP-ACT 1684797950 192.168.0.101 8332 typ srflx raddr 192.168.0.101 rport 8332
a=cryptoscale:1 client AES_CM_128_HMAC_SHA1_80 inline:NZUPXQBH7VwA0uuuHrlKbIXQP5l5KryO6RzqWgIH|2^31|1:1
a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:lzD/UHd0AVadfXle+0SWCbYj7Hrc93JurB87nLJr|2^31|1:1
a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:oliHsG5m4qlK0Gk4ww6+U7to0Vkj77HHgia8SCAM|2^31
a=maxptime:200
a=rtpmap:114 x-msrta/16000
a=fmtp:114 bitrate=29000
a=rtpmap:9 G722/8000
a=rtpmap:112 G7221/16000
a=fmtp:112 bitrate=24000
a=rtpmap:111 SIREN/16000
a=fmtp:111 bitrate=16000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:116 AAL2-G726-32/8000
a=rtpmap:115 x-msrta/8000
a=fmtp:115 bitrate=11800
a=rtpmap:4 G723/8000
a=rtpmap:97 RED/8000
a=rtpmap:13 CN/8000
a=rtpmap:118 CN/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=encryption:required

------=_NextPart_000_024F_01CBBD97.5707C730--

Response Data:

101  Progress Report
ms-diagnostics:  12006;reason="Trying next hop";source="lyncServer01.someDomain.com";PhoneUsage="Default Usage";PhoneRoute="ULOakvilleGW1";Gateway="medi02.someDomain.com";appName="OutboundRouting"

503  Service Unavailable
ms-diagnostics:  12000;reason="Routes available for this request but no available gateway at this point";source="lyncServer01.someDomain.com";appName="OutboundRouting";OriginalPresenceState="0";CurrentPresenceState="0";MeInsideUser="No";ConversationInitiatedBy="0";SourceNetwork="0";RemotePartyCanDoIM="No"

Resolution:
If this error continues to occur, please contact your network administrator. The network administrator can use a tool like winerror.exe from the Windows Resource Kit or lcserror.exe from the Office Communications Server Resource Kit in order to interpret any error codes listed above.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

-------------------------------------------------------------------------------------------------------------------------------------------------------------------

Solution

What I typically do when I run into such an issue is start a trace with Snooper and parse through the events to determine what might be the problem the following is what I found from a trace:

TL_INFO(TF_PROTOCOL) [0]09E0.1F28::01/27/2011-01:40:29.227.00011f91 (SIPStack,SIPAdminLog::TraceProtocolRecord:SIPAdminLog.cpp(125))$$begin_record
Trace-Correlation-Id: 3118858740
Instance-Id: 000292DA
Direction: outgoing;source="local"
Peer: ocspool2.someDomain.com:45413
Message-Type: response
Start-Line: SIP/2.0 504 Server time-out
From: "Terence Luk"<sip:tluk@someDomain.com>;tag=a4d0408d2e;epid=b7128e13bc
To: <sip:ocsedge01.someDomain.com@someDomain.com;gruu;opaque=srvr:MRAS:C5QkZVxV8kWdhEsgNBYIUgAA>;tag=0915A1DBDA1035365414B9264D44845B
CSeq: 1 SERVICE
Call-ID: 19c9dd85da044a1c8ebf07158f1abd00
Via: SIP/2.0/TLS 172.20.1.120:45413;branch=z9hG4bKB827B195.E9C3DEA583870967;branched=FALSE;ms-received-port=45413;ms-received-cid=8BEF00
Via: SIP/2.0/TLS 172.20.1.64:4051;branch=z9hG4bKD37BD492.2D2E3F4F11B86916;branched=FALSE;ms-received-port=4051;ms-received-cid=58B000
Via: SIP/2.0/TLS 192.168.0.101:5270;received=99.237.89.71;ms-received-port=5270;ms-received-cid=24D800
ms-diagnostics: 1038;reason="Failed to connect to a peer server";WinsockFailureCode="10060(WSAETIMEDOUT)";WinsockFailureDescription="The peer did not respond to the connection attempt";Peer="ocsedge01.someDomain.com";Port="5062";source="lyncserver01.someDomain.com"
Server: RTC/4.0
Content-Length: 0
Message-Body: –
$$end_record

image

What I like about traces is that if there are errors logged, you’re bound to get something that will tip you off and in this case, the problem was most likely the port between the Lync front-end server not being able to establish a connection to the Edge server via port 5062.  A quick test with telnet proves this:

image

Once I contacted the network engineer to open up the port, the problem went away.

1 comment:

Cory said...

What server did you run this trace on?